runsolver Copyright (C) 2010 Olivier ROUSSEL This is runsolver version 3.2.9a (svn: 651) This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. command line: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/e381ba7e-a192-11e0-8647-00163e1e087d.cudf.dudf-real.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/dudf-real//e381ba7e-a192-11e0-8647-00163e1e087d.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/e381ba7e-a192-11e0-8647-00163e1e087d.cudf.dudf-real.result Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 1.41 1.44 1.36 5/35 29955 /proc/meminfo: memFree=276808/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2592 CPUtime=0 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 11257172 2654208 280 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/29953/statm: 648 280 234 194 0 35 0 [pid=29954] ppid=29953 vsize=2592 CPUtime=0 /proc/29954/stat : 29954 (aspcud-paranoid) R 29953 29953 4778 34817 4778 4202560 110 0 0 0 0 0 0 0 25 0 1 0 11257172 2654208 133 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/29954/statm: 648 133 86 194 0 35 0 [pid=29955] ppid=29954 vsize=2592 CPUtime=0 /proc/29955/stat : 29955 (aspcud-paranoid) R 29954 29953 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11257172 2654208 47 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/29955/statm: 648 47 0 194 0 35 0 [startup+0.184933 s] /proc/loadavg: 1.41 1.44 1.36 5/35 29955 /proc/meminfo: memFree=276808/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=0.02 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 2932 0 0 0 0 2 0 25 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2600 [startup+0.210174 s] /proc/loadavg: 1.41 1.44 1.36 5/35 29955 /proc/meminfo: memFree=276808/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=0.02 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 2932 0 0 0 0 2 0 25 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2600 [startup+0.304932 s] /proc/loadavg: 1.41 1.44 1.36 5/35 29955 /proc/meminfo: memFree=276808/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=0.02 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 2932 0 0 0 0 2 0 25 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2600 [startup+0.704956 s] /proc/loadavg: 1.41 1.44 1.36 5/35 29955 /proc/meminfo: memFree=276808/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=0.02 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 2932 0 0 0 0 2 0 25 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2600 [startup+1.51189 s] /proc/loadavg: 1.38 1.43 1.35 2/37 29970 /proc/meminfo: memFree=240744/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=0.02 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 2932 0 0 0 0 2 0 25 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 [pid=29968] ppid=29953 vsize=1928 CPUtime=0 /proc/29968/stat : 29968 (clasp) S 29953 29953 4778 34817 4778 4202496 293 0 0 0 0 0 0 0 25 0 1 0 11257174 1974272 160 1283457024 134512640 136285277 4289340544 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/29968/statm: 482 160 144 433 0 47 0 [pid=29969] ppid=29953 vsize=2588 CPUtime=0 /proc/29969/stat : 29969 (gringo) S 29953 29953 4778 34817 4778 4202496 405 0 0 0 0 0 0 0 25 0 1 0 11257174 2650112 272 1283457024 134512640 136933539 4292196288 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/29969/statm: 647 272 242 592 0 52 0 [pid=29970] ppid=29953 vsize=38488 CPUtime=1.32 /proc/29970/stat : 29970 (cudf2lp) R 29953 29953 4778 34817 4778 4202496 10705 0 0 0 129 3 0 0 25 0 1 0 11257174 39411712 9106 1283457024 134512640 135786343 4286622336 18446744073709551615 135219508 0 0 6 0 0 0 0 17 0 0 0 0 /proc/29970/statm: 9622 9106 133 311 0 9309 0 Current children cumulated CPU time (s) 1.34 Current children cumulated vsize (KiB) 45604 Solver just ended. Dumping a history of the last processes samples [startup+1.61191 s] /proc/loadavg: 1.38 1.43 1.35 2/37 29970 /proc/meminfo: memFree=240744/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=0.02 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 2932 0 0 0 0 2 0 25 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 [pid=29968] ppid=29953 vsize=2064 CPUtime=0.01 /proc/29968/stat : 29968 (clasp) R 29953 29953 4778 34817 4778 4202496 372 0 0 0 1 0 0 0 18 0 1 0 11257174 2113536 239 1283457024 134512640 136285277 4289340544 18446744073709551615 134858534 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/29968/statm: 516 239 176 433 0 81 0 [pid=29969] ppid=29953 vsize=2872 CPUtime=0 /proc/29969/stat : 29969 (gringo) S 29953 29953 4778 34817 4778 4202496 474 0 0 0 0 0 0 0 18 0 1 0 11257174 2940928 341 1283457024 134512640 136933539 4292196288 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/29969/statm: 718 341 242 592 0 123 0 [pid=29970] ppid=29953 vsize=35364 CPUtime=1.4 /proc/29970/stat : 29970 (cudf2lp) R 29953 29953 4778 34817 4778 4202496 11335 0 0 0 137 3 0 0 25 0 1 0 11257174 36212736 8637 1283457024 134512640 135786343 4286622336 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0 /proc/29970/statm: 8841 8637 137 311 0 8528 0 Current children cumulated CPU time (s) 1.43 Current children cumulated vsize (KiB) 42900 [startup+2.01202 s] /proc/loadavg: 1.38 1.43 1.35 2/37 29970 /proc/meminfo: memFree=240744/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=1.52 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 14271 0 0 0 0 148 4 18 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 [pid=29968] ppid=29953 vsize=7980 CPUtime=0.03 /proc/29968/stat : 29968 (clasp) R 29953 29953 4778 34817 4778 4202496 1957 0 0 0 2 1 0 0 18 0 1 0 11257174 8171520 1681 1283457024 134512640 136285277 4289340544 18446744073709551615 134782592 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/29968/statm: 1995 1681 177 433 0 1560 0 [pid=29969] ppid=29953 vsize=13684 CPUtime=0.27 /proc/29969/stat : 29969 (gringo) R 29953 29953 4778 34817 4778 4202496 3239 0 0 0 26 1 0 0 18 0 1 0 11257174 14012416 2507 1283457024 134512640 136933539 4292196288 18446744073709551615 135633710 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/29969/statm: 3421 2507 253 592 0 2826 0 Current children cumulated CPU time (s) 1.82 Current children cumulated vsize (KiB) 24264 [startup+2.2121 s] /proc/loadavg: 1.38 1.43 1.35 2/35 29970 /proc/meminfo: memFree=248160/1048576 swapFree=0/0 [pid=29953] ppid=29952 vsize=2600 CPUtime=1.86 /proc/29953/stat : 29953 (aspcud-paranoid) S 29952 29953 4778 34817 4778 4202496 658 17960 0 0 0 0 178 8 17 0 1 0 11257172 2662400 299 1283457024 134512640 135304128 4291196496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/29953/statm: 650 299 251 194 0 37 0 [pid=29968] ppid=29953 vsize=11544 CPUtime=0.18 /proc/29968/stat : 29968 (clasp) R 29953 29953 4778 34817 4778 4202496 3129 0 0 0 17 1 0 0 18 0 1 0 11257174 11821056 2662 1283457024 134512640 136285277 4289340544 18446744073709551615 134893287 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/29968/statm: 2886 2662 234 433 0 2451 0 Current children cumulated CPU time (s) 2.04 Current children cumulated vsize (KiB) 14144 Child status: 0 Real time (s): 2.25191 CPU time (s): 2.07613 CPU user time (s): 1.97212 CPU system time (s): 0.104006 CPU usage (%): 92.194 Max. virtual memory (cumulated for all children) (KiB): 46584 getrusage(RUSAGE_CHILDREN,...) data: user time used= 1.97212 system time used= 0.104006 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 25400 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 434 involuntary context switches= 396 runsolver used 0 second user time and 0 second system time The end