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/packup2mp4pa-0.6/rand461.cudf.s-e-l.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/incremental/s-e-l/rand461.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand461.cudf.s-e-l.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.03 1.03 1.05 5/34 14259 /proc/meminfo: memFree=371072/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=4112 CPUtime=0.02 /proc/14259/stat : 14259 (packup) R 14258 14258 4778 34817 4778 4202496 523 0 0 0 2 0 0 0 25 0 1 0 10709998 4210688 451 1283457024 134512640 134752139 4289107040 18446744073709551615 134540207 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/14259/statm: 1028 451 286 59 0 192 0 [startup+0.203252 s] /proc/loadavg: 1.03 1.03 1.05 5/34 14259 /proc/meminfo: memFree=371072/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=11240 CPUtime=0.2 /proc/14259/stat : 14259 (packup) R 14258 14258 4778 34817 4778 4202496 2293 0 0 0 18 2 0 0 25 0 1 0 10709998 11509760 2221 1283457024 134512640 134752139 4289107040 18446744073709551615 4157193779 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/14259/statm: 2810 2221 286 59 0 1974 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 13816 [startup+0.313281 s] /proc/loadavg: 1.03 1.03 1.05 5/34 14259 /proc/meminfo: memFree=371072/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=14672 CPUtime=0.31 /proc/14259/stat : 14259 (packup) R 14258 14258 4778 34817 4778 4202496 3155 0 0 0 29 2 0 0 25 0 1 0 10709998 15024128 3083 1283457024 134512640 134752139 4289107040 18446744073709551615 134681659 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/14259/statm: 3668 3083 286 59 0 2832 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 17248 [startup+0.403306 s] /proc/loadavg: 1.03 1.03 1.05 5/34 14259 /proc/meminfo: memFree=371072/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=17180 CPUtime=0.4 /proc/14259/stat : 14259 (packup) R 14258 14258 4778 34817 4778 4202496 3786 0 0 0 38 2 0 0 25 0 1 0 10709998 17592320 3714 1283457024 134512640 134752139 4289107040 18446744073709551615 4157369920 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/14259/statm: 4295 3714 286 59 0 3459 0 Current children cumulated CPU time (s) 0.4 Current children cumulated vsize (KiB) 19756 [startup+0.713372 s] /proc/loadavg: 1.03 1.03 1.05 5/34 14259 /proc/meminfo: memFree=371072/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=25296 CPUtime=0.72 /proc/14259/stat : 14259 (packup) R 14258 14258 4778 34817 4778 4202496 5818 0 0 0 68 4 0 0 25 0 1 0 10709998 25903104 5746 1283457024 134512640 134752139 4289107040 18446744073709551615 134682011 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/14259/statm: 6324 5746 286 59 0 5488 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 27872 [startup+1.51351 s] /proc/loadavg: 1.03 1.03 1.05 2/35 14260 /proc/meminfo: memFree=334036/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=40072 CPUtime=1.24 /proc/14259/stat : 14259 (packup) S 14258 14258 4778 34817 4778 4202496 9664 0 0 0 106 18 0 0 25 0 1 0 10709998 41033728 9337 1283457024 134512640 134752139 4289107040 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/14259/statm: 10018 9337 324 59 0 9182 0 Current children cumulated CPU time (s) 1.24 Current children cumulated vsize (KiB) 42648 [startup+3.11392 s] /proc/loadavg: 1.03 1.03 1.05 2/37 14262 /proc/meminfo: memFree=313792/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=40076 CPUtime=2.83 /proc/14259/stat : 14259 (packup) S 14258 14258 4778 34817 4778 4202496 9722 9752 0 0 119 28 124 12 18 0 1 0 10709998 41037824 9346 1283457024 134512640 134752139 4289107040 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/14259/statm: 10019 9346 332 59 0 9183 0 Current children cumulated CPU time (s) 2.83 Current children cumulated vsize (KiB) 42652 [startup+6.30478 s] /proc/loadavg: 1.03 1.03 1.05 2/37 14264 /proc/meminfo: memFree=259232/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=40076 CPUtime=2.83 /proc/14259/stat : 14259 (packup) S 14258 14258 4778 34817 4778 4202496 9722 9752 0 0 119 28 124 12 18 0 1 0 10709998 41037824 9346 1283457024 134512640 134752139 4289107040 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/14259/statm: 10019 9346 332 59 0 9183 0 [pid=14263] ppid=14259 vsize=1668 CPUtime=0 /proc/14263/stat : 14263 (sh) S 14259 14258 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10710282 1708032 123 1283457024 134512640 134593992 4287486848 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/14263/statm: 417 123 108 20 0 44 0 [pid=14264] ppid=14263 vsize=90260 CPUtime=3.46 /proc/14264/stat : 14264 (minisatp_32) R 14263 14258 4778 34817 4778 4202496 28538 0 0 0 326 20 0 0 25 0 1 0 10710283 92426240 19423 1283457024 134512640 135413687 4290973424 18446744073709551615 134714576 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/14264/statm: 22565 19423 110 220 0 22343 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 134580 [startup+12.7064 s] /proc/loadavg: 1.02 1.02 1.05 2/37 14264 /proc/meminfo: memFree=183848/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=40076 CPUtime=2.83 /proc/14259/stat : 14259 (packup) S 14258 14258 4778 34817 4778 4202496 9722 9752 0 0 119 28 124 12 18 0 1 0 10709998 41037824 9346 1283457024 134512640 134752139 4289107040 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/14259/statm: 10019 9346 332 59 0 9183 0 [pid=14263] ppid=14259 vsize=1668 CPUtime=0 /proc/14263/stat : 14263 (sh) S 14259 14258 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10710282 1708032 123 1283457024 134512640 134593992 4287486848 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/14263/statm: 417 123 108 20 0 44 0 [pid=14264] ppid=14263 vsize=172780 CPUtime=9.85 /proc/14264/stat : 14264 (minisatp_32) R 14263 14258 4778 34817 4778 4202496 57035 0 0 0 954 31 0 0 25 0 1 0 10710283 176926720 37233 1283457024 134512640 135413687 4290973424 18446744073709551615 134653643 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/14264/statm: 43195 37233 110 220 0 42973 0 Current children cumulated CPU time (s) 12.68 Current children cumulated vsize (KiB) 217100 [startup+25.5109 s] /proc/loadavg: 1.02 1.02 1.05 2/37 14264 /proc/meminfo: memFree=187816/1048576 swapFree=0/0 [pid=14258] ppid=14257 vsize=2576 CPUtime=0 /proc/14258/stat : 14258 (packup2mp4pa-0.) S 14257 14258 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10709998 2637824 275 1283457024 134512640 135304128 4289168544 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/14258/statm: 644 275 233 194 0 31 0 [pid=14259] ppid=14258 vsize=38912 CPUtime=25.49 /proc/14259/stat : 14259 (packup) R 14258 14258 4778 34817 4778 4202496 17814 69974 0 0 123 31 2346 49 18 0 1 0 10709998 39845888 9068 1283457024 134512640 134752139 4289107040 18446744073709551615 4157339027 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/14259/statm: 9728 9068 345 59 0 8892 0 Current children cumulated CPU time (s) 25.49 Current children cumulated vsize (KiB) 41488 Solver just ended. Dumping a history of the last processes samples Child status: 0 Real time (s): 25.542 CPU time (s): 25.5296 CPU user time (s): 24.7135 CPU system time (s): 0.816051 CPU usage (%): 99.9515 Max. virtual memory (cumulated for all children) (KiB): 227640 getrusage(RUSAGE_CHILDREN,...) data: user time used= 24.7135 system time used= 0.816051 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 88586 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= 11 involuntary context switches= 362 runsolver used 0 second user time and 0 second system time The end