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/7bf50d1c-9b1b-11df-8b50-00163e46d37a.cudf.dudf-real.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/dudf-real//7bf50d1c-9b1b-11df-8b50-00163e46d37a.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/7bf50d1c-9b1b-11df-8b50-00163e46d37a.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.42 1.39 1.28 5/35 24651 /proc/meminfo: memFree=304708/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2592 CPUtime=0 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 19 0 1 0 11192148 2654208 280 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/24649/statm: 648 280 234 194 0 35 0 [pid=24650] ppid=24649 vsize=2592 CPUtime=0 /proc/24650/stat : 24650 (aspcud-paranoid) R 24649 24649 4778 34817 4778 4202560 110 0 0 0 0 0 0 0 25 0 1 0 11192148 2654208 133 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/24650/statm: 648 133 86 194 0 35 0 [pid=24651] ppid=24650 vsize=2592 CPUtime=0 /proc/24651/stat : 24651 (aspcud-paranoid) R 24650 24649 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11192148 2654208 47 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/24651/statm: 648 47 0 194 0 35 0 [startup+0.133494 s] /proc/loadavg: 1.42 1.39 1.28 5/35 24651 /proc/meminfo: memFree=304708/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=0.01 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 2933 0 0 0 0 1 0 25 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2600 [startup+0.205493 s] /proc/loadavg: 1.42 1.39 1.28 5/35 24651 /proc/meminfo: memFree=304708/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=0.01 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 2933 0 0 0 0 1 0 25 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2600 [startup+0.325585 s] /proc/loadavg: 1.42 1.39 1.28 5/35 24651 /proc/meminfo: memFree=304708/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=0.01 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 2933 0 0 0 0 1 0 25 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2600 [startup+0.705526 s] /proc/loadavg: 1.42 1.39 1.28 5/35 24651 /proc/meminfo: memFree=304708/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=0.01 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 2933 0 0 0 0 1 0 25 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2600 [startup+1.50763 s] /proc/loadavg: 1.39 1.39 1.28 2/37 24666 /proc/meminfo: memFree=267752/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=0.01 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 2933 0 0 0 0 1 0 25 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 [pid=24664] ppid=24649 vsize=1924 CPUtime=0 /proc/24664/stat : 24664 (clasp) S 24649 24649 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 11192150 1970176 159 1283457024 134512640 136285277 4288498608 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/24664/statm: 481 159 144 433 0 46 0 [pid=24665] ppid=24649 vsize=2584 CPUtime=0 /proc/24665/stat : 24665 (gringo) S 24649 24649 4778 34817 4778 4202496 405 0 0 0 0 0 0 0 25 0 1 0 11192150 2646016 272 1283457024 134512640 136933539 4291987328 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/24665/statm: 646 272 242 592 0 51 0 [pid=24666] ppid=24649 vsize=33324 CPUtime=1.33 /proc/24666/stat : 24666 (cudf2lp) R 24649 24649 4778 34817 4778 4202496 10789 0 0 0 127 6 0 0 25 0 1 0 11192150 34123776 8126 1283457024 134512640 135786343 4290067920 18446744073709551615 135191577 0 0 6 0 0 0 0 17 0 0 0 0 /proc/24666/statm: 8331 8126 133 311 0 8018 0 Current children cumulated CPU time (s) 1.34 Current children cumulated vsize (KiB) 40432 Solver just ended. Dumping a history of the last processes samples [startup+1.60763 s] /proc/loadavg: 1.39 1.39 1.28 2/37 24666 /proc/meminfo: memFree=267752/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=0.01 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 2933 0 0 0 0 1 0 25 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 [pid=24664] ppid=24649 vsize=3196 CPUtime=0 /proc/24664/stat : 24664 (clasp) R 24649 24649 4778 34817 4778 4202496 656 0 0 0 0 0 0 0 18 0 1 0 11192150 3272704 523 1283457024 134512640 136285277 4288498608 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/24664/statm: 799 523 176 433 0 364 0 [pid=24665] ppid=24649 vsize=4928 CPUtime=0.06 /proc/24665/stat : 24665 (gringo) R 24649 24649 4778 34817 4778 4202496 962 0 0 0 6 0 0 0 18 0 1 0 11192150 5046272 715 1283457024 134512640 136933539 4291987328 18446744073709551615 136192602 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/24665/statm: 1232 715 242 592 0 637 0 [pid=24666] ppid=24649 vsize=33328 CPUtime=1.36 /proc/24666/stat : 24666 (cudf2lp) R 24649 24649 4778 34817 4778 4202496 10794 0 0 0 130 6 0 0 25 0 1 0 11192150 34127872 8131 1283457024 134512640 135786343 4290067920 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0 /proc/24666/statm: 8332 8131 137 311 0 8019 0 Current children cumulated CPU time (s) 1.43 Current children cumulated vsize (KiB) 44052 [startup+2.00771 s] /proc/loadavg: 1.39 1.39 1.28 2/37 24666 /proc/meminfo: memFree=267752/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=1.5 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 13731 0 0 0 0 142 8 18 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 [pid=24664] ppid=24649 vsize=9408 CPUtime=0.04 /proc/24664/stat : 24664 (clasp) R 24649 24649 4778 34817 4778 4202496 2380 0 0 0 3 1 0 0 18 0 1 0 11192150 9633792 2043 1283457024 134512640 136285277 4288498608 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/24664/statm: 2352 2043 177 433 0 1917 0 [pid=24665] ppid=24649 vsize=15776 CPUtime=0.29 /proc/24665/stat : 24665 (gringo) R 24649 24649 4778 34817 4778 4202496 3724 0 0 0 29 0 0 0 18 0 1 0 11192150 16154624 2994 1283457024 134512640 136933539 4291987328 18446744073709551615 134688189 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/24665/statm: 3944 2994 253 592 0 3349 0 Current children cumulated CPU time (s) 1.83 Current children cumulated vsize (KiB) 27784 [startup+2.10777 s] /proc/loadavg: 1.39 1.39 1.28 2/37 24666 /proc/meminfo: memFree=267752/1048576 swapFree=0/0 [pid=24649] ppid=24648 vsize=2600 CPUtime=1.84 /proc/24649/stat : 24649 (aspcud-paranoid) S 24648 24649 4778 34817 4778 4202496 655 17971 0 0 0 0 174 10 17 0 1 0 11192148 2662400 299 1283457024 134512640 135304128 4288943152 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24649/statm: 650 299 251 194 0 37 0 [pid=24664] ppid=24649 vsize=11928 CPUtime=0.1 /proc/24664/stat : 24664 (clasp) R 24649 24649 4778 34817 4778 4202496 3021 0 0 0 8 2 0 0 18 0 1 0 11192150 12214272 2684 1283457024 134512640 136285277 4288498608 18446744073709551615 135070385 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/24664/statm: 2982 2684 189 433 0 2547 0 Current children cumulated CPU time (s) 1.94 Current children cumulated vsize (KiB) 14528 Child status: 0 Real time (s): 2.2032 CPU time (s): 2.04413 CPU user time (s): 1.90812 CPU system time (s): 0.136008 CPU usage (%): 92.7798 Max. virtual memory (cumulated for all children) (KiB): 47388 getrusage(RUSAGE_CHILDREN,...) data: user time used= 1.90812 system time used= 0.136008 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 25924 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= 505 involuntary context switches= 430 runsolver used 0 second user time and 0.004 second system time The end