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/201012061533/aspcud-paranoid-1.3/9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./aspcud-paranoid-1.3 /home/misc2010/data/2010/debian-dudf//9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf /home/misc2010/tmp/201012061533/aspcud-paranoid-1.3/9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf.debian-dudf.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.51 1.41 1.28 5/47 30613 /proc/meminfo: memFree=642540/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2588 CPUtime=0 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 375 0 0 0 0 0 0 0 23 0 1 0 876584361 2650112 281 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/30611/statm: 647 281 237 194 0 33 0 [pid=30612] ppid=30611 vsize=2588 CPUtime=0 /proc/30612/stat : 30612 (aspcud-paranoid) R 30611 30611 2059 34821 2220 4202560 105 0 0 0 0 0 0 0 25 0 1 0 876584362 2650112 127 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/30612/statm: 647 127 82 194 0 33 0 [pid=30613] ppid=30612 vsize=2588 CPUtime=0 /proc/30613/stat : 30613 (aspcud-paranoid) R 30612 30611 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 876584362 2650112 45 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/30613/statm: 647 45 0 194 0 33 0 [startup+0.161388 s] /proc/loadavg: 1.51 1.41 1.28 5/47 30613 /proc/meminfo: memFree=642540/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=0 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 663 2932 0 0 0 0 0 0 25 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2600 [startup+0.21141 s] /proc/loadavg: 1.51 1.41 1.28 5/47 30613 /proc/meminfo: memFree=642540/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=0 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 663 2932 0 0 0 0 0 0 25 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2600 [startup+0.311417 s] /proc/loadavg: 1.51 1.41 1.28 5/47 30613 /proc/meminfo: memFree=642540/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=0 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 663 2932 0 0 0 0 0 0 25 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2600 [startup+0.711484 s] /proc/loadavg: 1.51 1.41 1.28 5/47 30613 /proc/meminfo: memFree=642540/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=0 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 663 2932 0 0 0 0 0 0 25 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2600 [startup+1.51163 s] /proc/loadavg: 1.51 1.41 1.28 2/49 30628 /proc/meminfo: memFree=600016/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=0 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 663 2932 0 0 0 0 0 0 25 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 [pid=30626] ppid=30611 vsize=6600 CPUtime=0 /proc/30626/stat : 30626 (clasp) S 30611 30611 2059 34821 2220 4202496 1560 0 0 0 0 0 0 0 18 0 1 0 876584363 6758400 1346 1283457024 134512640 136223643 4292923376 18446744073709551615 135666734 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30626/statm: 1650 1346 174 418 0 1230 0 [pid=30627] ppid=30611 vsize=9324 CPUtime=0.22 /proc/30627/stat : 30627 (gringo) R 30611 30611 2059 34821 2220 4202496 2498 0 0 0 21 1 0 0 18 0 1 0 876584363 9547776 1592 1283457024 134512640 136959103 4292544528 18446744073709551615 134587530 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30627/statm: 2331 1592 247 598 0 1730 0 [pid=30628] ppid=30611 vsize=40868 CPUtime=1.24 /proc/30628/stat : 30628 (cudf2lp) R 30611 30611 2059 34821 2220 4202496 13291 0 0 0 118 6 0 0 25 0 1 0 876584363 41848832 10021 1283457024 134512640 135749571 4289637728 18446744073709551615 135237662 0 0 6 0 0 0 0 17 0 0 0 0 /proc/30628/statm: 10217 10021 129 302 0 9913 0 Current children cumulated CPU time (s) 1.46 Current children cumulated vsize (KiB) 59392 [startup+3.1119 s] /proc/loadavg: 1.51 1.41 1.28 3/49 30628 /proc/meminfo: memFree=571124/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=1.53 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 664 16227 0 0 0 0 145 8 18 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 [pid=30626] ppid=30611 vsize=33344 CPUtime=0.17 /proc/30626/stat : 30626 (clasp) R 30611 30611 2059 34821 2220 4202496 9417 0 0 0 13 4 0 0 18 0 1 0 876584363 34144256 7917 1283457024 134512640 136223643 4292923376 18446744073709551615 135666734 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30626/statm: 8336 7917 174 418 0 7916 0 [pid=30627] ppid=30611 vsize=53424 CPUtime=1.38 /proc/30627/stat : 30627 (gringo) R 30611 30611 2059 34821 2220 4202496 15801 0 0 0 136 2 0 0 18 0 1 0 876584363 54706176 11041 1283457024 134512640 136959103 4292544528 18446744073709551615 136161134 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30627/statm: 13356 11041 256 598 0 12755 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 89368 [startup+6.31301 s] /proc/loadavg: 1.47 1.40 1.28 2/47 30628 /proc/meminfo: memFree=591244/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=3.38 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 664 34432 0 0 0 0 325 13 18 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 [pid=30626] ppid=30611 vsize=55888 CPUtime=2.91 /proc/30626/stat : 30626 (clasp) R 30611 30611 2059 34821 2220 4202496 16195 0 0 0 284 7 0 0 22 0 1 0 876584363 57229312 12876 1283457024 134512640 136223643 4292923376 18446744073709551615 134870687 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30626/statm: 13972 12876 223 418 0 13552 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 58488 Solver just ended. Dumping a history of the last processes samples [startup+6.41304 s] /proc/loadavg: 1.47 1.40 1.28 2/47 30628 /proc/meminfo: memFree=591244/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=3.38 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 664 34432 0 0 0 0 325 13 18 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 [pid=30626] ppid=30611 vsize=55888 CPUtime=3.01 /proc/30626/stat : 30626 (clasp) R 30611 30611 2059 34821 2220 4202496 16195 0 0 0 294 7 0 0 22 0 1 0 876584363 57229312 12876 1283457024 134512640 136223643 4292923376 18446744073709551615 134578828 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30626/statm: 13972 12876 223 418 0 13552 0 Current children cumulated CPU time (s) 6.39 Current children cumulated vsize (KiB) 58488 [startup+7.21332 s] /proc/loadavg: 1.47 1.40 1.28 2/47 30628 /proc/meminfo: memFree=591244/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=3.38 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 664 34432 0 0 0 0 325 13 18 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 [pid=30626] ppid=30611 vsize=55888 CPUtime=3.81 /proc/30626/stat : 30626 (clasp) R 30611 30611 2059 34821 2220 4202496 16195 0 0 0 374 7 0 0 25 0 1 0 876584363 57229312 12876 1283457024 134512640 136223643 4292923376 18446744073709551615 134870708 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30626/statm: 13972 12876 223 418 0 13552 0 Current children cumulated CPU time (s) 7.19 Current children cumulated vsize (KiB) 58488 [startup+7.61346 s] /proc/loadavg: 1.47 1.40 1.28 2/47 30628 /proc/meminfo: memFree=591244/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=3.38 /proc/30611/stat : 30611 (aspcud-paranoid) S 30610 30611 2059 34821 2220 4202496 664 34432 0 0 0 0 325 13 18 0 1 0 876584361 2662400 300 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30611/statm: 650 300 253 194 0 36 0 [pid=30626] ppid=30611 vsize=55888 CPUtime=4.21 /proc/30626/stat : 30626 (clasp) R 30611 30611 2059 34821 2220 4202496 16198 0 0 0 414 7 0 0 25 0 1 0 876584363 57229312 12879 1283457024 134512640 136223643 4292923376 18446744073709551615 134870687 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30626/statm: 13972 12879 225 418 0 13552 0 Current children cumulated CPU time (s) 7.59 Current children cumulated vsize (KiB) 58488 [startup+7.81355 s] /proc/loadavg: 1.47 1.40 1.28 2/47 30628 /proc/meminfo: memFree=591120/1048576 swapFree=2078744/2097144 [pid=30611] ppid=30610 vsize=2600 CPUtime=7.8 /proc/30611/stat : 30611 (aspcud-paranoid) R 30610 30611 2059 34821 2220 4202496 758 51249 0 0 0 1 759 20 22 0 1 0 876584361 2662400 305 1283457024 134512640 135304128 4287179392 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0 /proc/30611/statm: 650 305 258 194 0 36 0 Current children cumulated CPU time (s) 7.8 Current children cumulated vsize (KiB) 2600 Child status: 0 Real time (s): 7.83488 CPU time (s): 7.84049 CPU user time (s): 7.60048 CPU system time (s): 0.240015 CPU usage (%): 100.072 Max. virtual memory (cumulated for all children) (KiB): 105864 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.60048 system time used= 0.240015 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 55182 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= 2846 involuntary context switches= 2299 runsolver used 0 second user time and 0 second system time The end