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/201108241238/aspuncud-trendy-1.3/rand285.cudf.s-e-l.log.runsolver ./aspuncud-trendy-1.3 /home/misc2010/data/2011/incremental/s-e-l/rand285.cudf /home/misc2010/tmp/201108241238/aspuncud-trendy-1.3/rand285.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.01 1.03 1.00 5/37 8087 /proc/meminfo: memFree=555212/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2588 CPUtime=0 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 2016114 2650112 279 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/8085/statm: 647 279 234 194 0 34 0 [pid=8086] ppid=8085 vsize=2588 CPUtime=0 /proc/8086/stat : 8086 (aspuncud-trendy) R 8085 8085 1511 34817 1511 4202560 110 0 0 0 0 0 0 0 25 0 1 0 2016114 2650112 132 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/8086/statm: 647 132 86 194 0 34 0 [pid=8087] ppid=8086 vsize=2588 CPUtime=0 /proc/8087/stat : 8087 (aspuncud-trendy) R 8086 8085 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 2016114 2650112 46 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/8087/statm: 647 46 0 194 0 34 0 [startup+0.141444 s] /proc/loadavg: 1.01 1.03 1.00 5/37 8087 /proc/meminfo: memFree=555212/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=0 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 621 2228 0 0 0 0 0 0 25 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.205457 s] /proc/loadavg: 1.01 1.03 1.00 5/37 8087 /proc/meminfo: memFree=555212/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=0 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 621 2228 0 0 0 0 0 0 25 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.305466 s] /proc/loadavg: 1.01 1.03 1.00 5/37 8087 /proc/meminfo: memFree=555212/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=0 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 621 2228 0 0 0 0 0 0 25 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.705502 s] /proc/loadavg: 1.01 1.03 1.00 5/37 8087 /proc/meminfo: memFree=555212/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=0 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 621 2228 0 0 0 0 0 0 25 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+1.50832 s] /proc/loadavg: 1.01 1.03 1.00 2/39 8099 /proc/meminfo: memFree=522556/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=0 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 621 2228 0 0 0 0 0 0 25 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 [pid=8097] ppid=8085 vsize=5680 CPUtime=0 /proc/8097/stat : 8097 (unclasp) S 8085 8085 1511 34817 1511 4202496 1004 0 0 0 0 0 0 0 18 0 1 0 2016115 5816320 869 1283457024 134512640 135121179 4294359504 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/8097/statm: 1420 869 275 149 0 611 0 [pid=8098] ppid=8085 vsize=6252 CPUtime=0.11 /proc/8098/stat : 8098 (gringo) R 8085 8085 1511 34817 1511 4202496 1413 0 0 0 11 0 0 0 18 0 1 0 2016115 6402048 962 1283457024 134512640 137056543 4288488400 18446744073709551615 134903435 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/8098/statm: 1563 962 253 622 0 938 0 [pid=8099] ppid=8085 vsize=30576 CPUtime=1.1 /proc/8099/stat : 8099 (cudf2lp) R 8085 8085 1511 34817 1511 4202496 10049 0 0 0 105 5 0 0 25 0 1 0 2016115 31309824 7426 1283457024 134512640 135786343 4294359520 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0 /proc/8099/statm: 7644 7426 137 311 0 7331 0 Current children cumulated CPU time (s) 1.21 Current children cumulated vsize (KiB) 45100 [startup+3.10902 s] /proc/loadavg: 1.01 1.03 1.00 3/38 8100 /proc/meminfo: memFree=513588/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=2.07 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 622 20388 0 0 0 0 196 11 15 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 [pid=8097] ppid=8085 vsize=31168 CPUtime=0.76 /proc/8097/stat : 8097 (unclasp) R 8085 8085 1511 34817 1511 4202496 10324 0 0 0 72 4 0 0 18 0 1 0 2016115 31916032 6879 1283457024 134512640 135121179 4294359504 18446744073709551615 134891399 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/8097/statm: 7792 6879 328 149 0 6983 0 Current children cumulated CPU time (s) 2.83 Current children cumulated vsize (KiB) 33760 [startup+6.31029 s] /proc/loadavg: 1.01 1.03 1.00 2/37 8100 /proc/meminfo: memFree=515216/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=2.07 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 622 20388 0 0 0 0 196 11 15 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 [pid=8097] ppid=8085 vsize=30420 CPUtime=3.95 /proc/8097/stat : 8097 (unclasp) R 8085 8085 1511 34817 1511 4202496 52295 0 0 0 374 21 0 0 25 0 1 0 2016115 31150080 6727 1283457024 134512640 135121179 4294359504 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/8097/statm: 7605 6727 328 149 0 6796 0 Current children cumulated CPU time (s) 6.02 Current children cumulated vsize (KiB) 33012 [startup+12.7128 s] /proc/loadavg: 1.01 1.03 1.00 2/37 8101 /proc/meminfo: memFree=514976/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=2.07 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 622 20388 0 0 0 0 196 11 15 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 [pid=8097] ppid=8085 vsize=31072 CPUtime=10.35 /proc/8097/stat : 8097 (unclasp) R 8085 8085 1511 34817 1511 4202496 114587 0 0 0 984 51 0 0 25 0 1 0 2016115 31817728 6863 1283457024 134512640 135121179 4294359504 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/8097/statm: 7768 6863 333 149 0 6959 0 Current children cumulated CPU time (s) 12.42 Current children cumulated vsize (KiB) 33664 Solver just ended. Dumping a history of the last processes samples [startup+12.8028 s] /proc/loadavg: 1.01 1.03 1.00 2/37 8101 /proc/meminfo: memFree=514976/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=2.07 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 622 20388 0 0 0 0 196 11 15 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 [pid=8097] ppid=8085 vsize=31072 CPUtime=10.44 /proc/8097/stat : 8097 (unclasp) R 8085 8085 1511 34817 1511 4202496 115430 0 0 0 992 52 0 0 25 0 1 0 2016115 31817728 6845 1283457024 134512640 135121179 4294359504 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/8097/statm: 7768 6845 333 149 0 6959 0 Current children cumulated CPU time (s) 12.51 Current children cumulated vsize (KiB) 33664 [startup+13.6031 s] /proc/loadavg: 1.01 1.03 1.00 2/37 8101 /proc/meminfo: memFree=515100/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=2.07 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 622 20388 0 0 0 0 196 11 15 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 [pid=8097] ppid=8085 vsize=31312 CPUtime=11.23 /proc/8097/stat : 8097 (unclasp) R 8085 8085 1511 34817 1511 4202496 122427 0 0 0 1070 53 0 0 25 0 1 0 2016115 32063488 6909 1283457024 134512640 135121179 4294359504 18446744073709551615 134734450 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/8097/statm: 7828 6909 333 149 0 7019 0 Current children cumulated CPU time (s) 13.3 Current children cumulated vsize (KiB) 33904 [startup+14.0033 s] /proc/loadavg: 1.01 1.03 1.00 2/37 8101 /proc/meminfo: memFree=515100/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=2.07 /proc/8085/stat : 8085 (aspuncud-trendy) S 8084 8085 1511 34817 1511 4202496 622 20388 0 0 0 0 196 11 15 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 [pid=8097] ppid=8085 vsize=31312 CPUtime=11.63 /proc/8097/stat : 8097 (unclasp) R 8085 8085 1511 34817 1511 4202496 125639 0 0 0 1108 55 0 0 25 0 1 0 2016115 32063488 6909 1283457024 134512640 135121179 4294359504 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/8097/statm: 7828 6909 333 149 0 7019 0 Current children cumulated CPU time (s) 13.7 Current children cumulated vsize (KiB) 33904 [startup+14.1133 s] /proc/loadavg: 1.01 1.03 1.00 2/37 8101 /proc/meminfo: memFree=515100/1048576 swapFree=0/0 [pid=8085] ppid=8084 vsize=2592 CPUtime=13.82 /proc/8085/stat : 8085 (aspuncud-trendy) R 8084 8085 1511 34817 1511 4202496 791 148549 0 0 0 0 1314 68 20 0 1 0 2016114 2654208 297 1283457024 134512640 135304128 4289391824 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0 /proc/8085/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 13.82 Current children cumulated vsize (KiB) 2592 Child status: 0 Real time (s): 14.1152 CPU time (s): 13.8329 CPU user time (s): 13.1448 CPU system time (s): 0.688043 CPU usage (%): 98.0001 Max. virtual memory (cumulated for all children) (KiB): 61448 getrusage(RUSAGE_CHILDREN,...) data: user time used= 13.1448 system time used= 0.688043 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 149759 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= 1253 involuntary context switches= 1071 runsolver used 0 second user time and 0 second system time The end