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/4e539b28-d46c-11df-8f4f-00163e3d3b7c.cudf.dudf-real.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/dudf-real//4e539b28-d46c-11df-8f4f-00163e3d3b7c.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/4e539b28-d46c-11df-8f4f-00163e3d3b7c.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.50 1.41 1.21 5/36 21040 /proc/meminfo: memFree=333996/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2588 CPUtime=0 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 18 0 1 0 11135925 2650112 280 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/21037/statm: 647 280 234 194 0 34 0 [pid=21038] ppid=21037 vsize=2588 CPUtime=0 /proc/21038/stat : 21038 (aspcud-paranoid) S 21037 21037 4778 34817 4778 4202560 118 0 0 0 0 0 0 0 18 0 1 0 11135926 2650112 134 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0 /proc/21038/statm: 647 134 87 194 0 34 0 [pid=21039] ppid=21038 vsize=2588 CPUtime=0 /proc/21039/stat : 21039 (aspcud-paranoid) R 21038 21037 4778 34817 4778 4202560 127 0 0 0 0 0 0 0 25 0 1 0 11135926 2650112 151 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/21039/statm: 647 151 104 194 0 34 0 [pid=21040] ppid=21039 vsize=2588 CPUtime=0 /proc/21040/stat : 21040 (aspcud-paranoid) R 21039 21037 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11135926 2650112 47 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/21040/statm: 647 47 0 194 0 34 0 [startup+0.165055 s] /proc/loadavg: 1.50 1.41 1.21 5/36 21040 /proc/meminfo: memFree=333996/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=0.01 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 2938 0 0 0 0 0 1 25 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.205078 s] /proc/loadavg: 1.50 1.41 1.21 5/36 21040 /proc/meminfo: memFree=333996/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=0.01 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 2938 0 0 0 0 0 1 25 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.305083 s] /proc/loadavg: 1.50 1.41 1.21 5/36 21040 /proc/meminfo: memFree=333996/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=0.01 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 2938 0 0 0 0 0 1 25 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.705092 s] /proc/loadavg: 1.50 1.41 1.21 5/36 21040 /proc/meminfo: memFree=333996/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=0.01 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 2938 0 0 0 0 0 1 25 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+1.50514 s] /proc/loadavg: 1.50 1.41 1.21 2/37 21054 /proc/meminfo: memFree=297876/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=0.01 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 2938 0 0 0 0 0 1 25 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 [pid=21052] ppid=21037 vsize=1928 CPUtime=0 /proc/21052/stat : 21052 (clasp) S 21037 21037 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 11135927 1974272 160 1283457024 134512640 136285277 4287968048 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/21052/statm: 482 160 144 433 0 47 0 [pid=21053] ppid=21037 vsize=2588 CPUtime=0 /proc/21053/stat : 21053 (gringo) S 21037 21037 4778 34817 4778 4202496 404 0 0 0 0 0 0 0 25 0 1 0 11135927 2650112 272 1283457024 134512640 136933539 4290022816 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/21053/statm: 647 272 242 592 0 52 0 [pid=21054] ppid=21037 vsize=32892 CPUtime=1.2 /proc/21054/stat : 21054 (cudf2lp) R 21037 21037 4778 34817 4778 4202496 9297 0 0 0 118 2 0 0 25 0 1 0 11135927 33681408 7650 1283457024 134512640 135786343 4287581040 18446744073709551615 134546832 0 0 6 0 0 0 0 17 0 0 0 0 /proc/21054/statm: 8223 7650 133 311 0 7910 0 Current children cumulated CPU time (s) 1.21 Current children cumulated vsize (KiB) 40004 [startup+3.10752 s] /proc/loadavg: 1.50 1.41 1.21 3/36 21054 /proc/meminfo: memFree=298872/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=2.46 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 23562 0 0 0 0 238 8 15 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 [pid=21052] ppid=21037 vsize=29620 CPUtime=0.35 /proc/21052/stat : 21052 (clasp) R 21037 21037 4778 34817 4778 4202496 8504 0 0 0 31 4 0 0 18 0 1 0 11135927 30330880 7080 1283457024 134512640 136285277 4287968048 18446744073709551615 134899833 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/21052/statm: 7405 7080 217 433 0 6970 0 Current children cumulated CPU time (s) 2.81 Current children cumulated vsize (KiB) 32216 Solver just ended. Dumping a history of the last processes samples [startup+3.20753 s] /proc/loadavg: 1.50 1.41 1.21 3/36 21054 /proc/meminfo: memFree=298872/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=2.46 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 23562 0 0 0 0 238 8 15 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 [pid=21052] ppid=21037 vsize=29620 CPUtime=0.45 /proc/21052/stat : 21052 (clasp) R 21037 21037 4778 34817 4778 4202496 8506 0 0 0 41 4 0 0 18 0 1 0 11135927 30330880 7082 1283457024 134512640 136285277 4287968048 18446744073709551615 134905622 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/21052/statm: 7405 7082 218 433 0 6970 0 Current children cumulated CPU time (s) 2.91 Current children cumulated vsize (KiB) 32216 [startup+3.4076 s] /proc/loadavg: 1.54 1.42 1.21 2/35 21054 /proc/meminfo: memFree=286372/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=2.46 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 23562 0 0 0 0 238 8 15 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 [pid=21052] ppid=21037 vsize=29076 CPUtime=0.65 /proc/21052/stat : 21052 (clasp) R 21037 21037 4778 34817 4778 4202496 8532 0 0 0 61 4 0 0 18 0 1 0 11135927 29773824 7017 1283457024 134512640 136285277 4287968048 18446744073709551615 134893147 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/21052/statm: 7269 7017 234 433 0 6834 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 31672 [startup+3.50888 s] /proc/loadavg: 1.54 1.42 1.21 2/35 21054 /proc/meminfo: memFree=286372/1048576 swapFree=0/0 [pid=21037] ppid=21036 vsize=2596 CPUtime=2.46 /proc/21037/stat : 21037 (aspcud-paranoid) S 21036 21037 4778 34817 4778 4202496 649 23562 0 0 0 0 238 8 15 0 1 0 11135925 2658304 299 1283457024 134512640 135304128 4292980736 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/21037/statm: 649 299 251 194 0 36 0 [pid=21052] ppid=21037 vsize=24924 CPUtime=0.75 /proc/21052/stat : 21052 (clasp) R 21037 21037 4778 34817 4778 4202496 8540 0 0 0 70 5 0 0 18 0 1 0 11135927 25522176 4963 1283457024 134512640 136285277 4287968048 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/21052/statm: 6231 4963 242 433 0 5796 0 Current children cumulated CPU time (s) 3.21 Current children cumulated vsize (KiB) 27520 Child status: 0 Real time (s): 3.54181 CPU time (s): 3.2562 CPU user time (s): 3.10419 CPU system time (s): 0.152009 CPU usage (%): 91.9361 Max. virtual memory (cumulated for all children) (KiB): 59260 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.10419 system time used= 0.152009 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 36669 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= 1097 involuntary context switches= 812 runsolver used 0 second user time and 0 second system time The end