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: runsolver -W 300 -M 1124 -w /home/cbse/results/sarge-etch-lenny/logs/98.runsolver.smart smart --config-file=/home/cbse/var/lib/smart/config install xabacus wmanx rwall amiga-fdisk-cross libganglia1-dev Enforcing wall clock limit (soft limit, will send signal-name then SIGKILL): 300 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: 0.99 0.97 0.97 2/53 13923 /proc/meminfo: memFree=390580/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=26808 CPUtime=0 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 605 0 0 0 0 0 0 0 20 0 1 0 7422693 27451392 497 18446744073709551615 4194304 6763684 140736915969280 140736915959816 4353659 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 6702 497 368 628 0 161 0 [startup+0.14923 s] /proc/loadavg: 0.99 0.97 0.97 2/53 13923 /proc/meminfo: memFree=390580/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=120148 CPUtime=0.13 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 10109 0 0 0 11 2 0 0 20 0 1 0 7422693 123031552 8829 18446744073709551615 4194304 6763684 140736915969280 140736915964280 5517868 0 0 16781312 2 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 30037 8829 1043 628 0 7620 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 120148 [startup+0.200275 s] /proc/loadavg: 0.99 0.97 0.97 2/53 13923 /proc/meminfo: memFree=390580/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=122268 CPUtime=0.19 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 12039 412 0 0 16 3 0 0 20 0 1 0 7422693 125202432 8311 18446744073709551615 4194304 6763684 140736915969280 140736915965336 140506679485437 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 30567 8311 1058 628 0 7120 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 122268 [startup+0.300238 s] /proc/loadavg: 0.99 0.97 0.97 2/53 13923 /proc/meminfo: memFree=390580/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=139308 CPUtime=0.28 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 18835 412 0 0 24 4 0 0 20 0 1 0 7422693 142651392 12585 18446744073709551615 4194304 6763684 140736915969280 140736915965256 5511980 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 34827 12585 1059 628 0 11380 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 139308 [startup+0.700183 s] /proc/loadavg: 0.99 0.97 0.97 2/53 13923 /proc/meminfo: memFree=390580/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=200396 CPUtime=0.69 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 37677 412 0 0 59 10 0 0 20 0 1 0 7422693 205205504 27850 18446744073709551615 4194304 6763684 140736915969280 140736915965256 5518033 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 50099 27850 1059 628 0 26652 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 200396 [startup+1.5002 s] /proc/loadavg: 0.99 0.97 0.97 2/54 13926 /proc/meminfo: memFree=246492/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=236420 CPUtime=1.48 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 52868 412 0 0 134 14 0 0 20 0 1 0 7422693 242094080 36864 18446744073709551615 4194304 6763684 140736915969280 140736915965808 5743900 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 59105 36864 1068 628 0 35658 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 236420 [startup+3.1002 s] /proc/loadavg: 0.99 0.97 0.97 2/54 13926 /proc/meminfo: memFree=207184/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=276008 CPUtime=3.08 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 62778 412 0 0 293 15 0 0 20 0 1 0 7422693 282632192 46763 18446744073709551615 4194304 6763684 140736915969280 140736915966232 140506661242376 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69002 46763 1070 628 0 45555 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 276008 [startup+6.30019 s] /proc/loadavg: 0.99 0.97 0.97 2/54 13926 /proc/meminfo: memFree=207184/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=276008 CPUtime=6.27 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 62781 412 0 0 612 15 0 0 20 0 1 0 7422693 282632192 46766 18446744073709551615 4194304 6763684 140736915969280 140736915966232 140506661240672 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69002 46766 1073 628 0 45555 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 276008 [startup+12.7002 s] /proc/loadavg: 0.99 0.97 0.97 2/54 13926 /proc/meminfo: memFree=207060/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=276008 CPUtime=12.64 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 62782 412 0 0 1249 15 0 0 20 0 1 0 7422693 282632192 46766 18446744073709551615 4194304 6763684 140736915969280 140736915966232 140506661240538 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69002 46766 1073 628 0 45555 0 Current children cumulated CPU time (s) 12.64 Current children cumulated vsize (KiB) 276008 [startup+25.5002 s] /proc/loadavg: 0.99 0.97 0.97 4/55 14063 /proc/meminfo: memFree=206556/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=276008 CPUtime=23.9 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 62782 412 0 0 2375 15 0 0 20 0 1 0 7422693 282632192 46766 18446744073709551615 4194304 6763684 140736915969280 140736915966232 140506661240538 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69002 46766 1073 628 0 45555 0 Current children cumulated CPU time (s) 23.9 Current children cumulated vsize (KiB) 276008 [startup+51.1002 s] /proc/loadavg: 1.05 0.99 0.98 2/54 14155 /proc/meminfo: memFree=206564/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=276008 CPUtime=48.04 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 62782 412 0 0 4789 15 0 0 20 0 1 0 7422693 282632192 46766 18446744073709551615 4194304 6763684 140736915969280 140736915966232 140506661244208 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69002 46766 1073 628 0 45555 0 Current children cumulated CPU time (s) 48.04 Current children cumulated vsize (KiB) 276008 [startup+102.3 s] /proc/loadavg: 1.02 0.99 0.98 2/54 14155 /proc/meminfo: memFree=206564/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=276008 CPUtime=99.05 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 62782 412 0 0 9890 15 0 0 20 0 1 0 7422693 282632192 46766 18446744073709551615 4194304 6763684 140736915969280 140736915966232 140506661244216 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69002 46766 1073 628 0 45555 0 Current children cumulated CPU time (s) 99.05 Current children cumulated vsize (KiB) 276008 [startup+162.3 s] /proc/loadavg: 1.06 1.00 0.98 2/54 14155 /proc/meminfo: memFree=206564/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=276008 CPUtime=158.82 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 62783 412 0 0 15867 15 0 0 20 0 1 0 7422693 282632192 46766 18446744073709551615 4194304 6763684 140736915969280 140736915966232 140506661244208 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69002 46766 1073 628 0 45555 0 Current children cumulated CPU time (s) 158.82 Current children cumulated vsize (KiB) 276008 [startup+222.307 s] /proc/loadavg: 1.02 1.00 0.98 2/54 14155 /proc/meminfo: memFree=204704/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=278124 CPUtime=218.6 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 63313 412 0 0 21845 15 0 0 20 0 1 0 7422693 284798976 47295 18446744073709551615 4194304 6763684 140736915969280 140736915910344 140506661240558 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69531 47295 1073 628 0 46084 0 Current children cumulated CPU time (s) 218.6 Current children cumulated vsize (KiB) 278124 [startup+282.3 s] /proc/loadavg: 1.01 1.00 0.98 2/54 14155 /proc/meminfo: memFree=204456/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=278284 CPUtime=278.37 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 63364 412 0 0 27822 15 0 0 20 0 1 0 7422693 284962816 47346 18446744073709551615 4194304 6763684 140736915969280 140736915911400 140506661240534 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69571 47346 1073 628 0 46124 0 Current children cumulated CPU time (s) 278.37 Current children cumulated vsize (KiB) 278284 Maximum wall clock time exceeded: sending signal-name then SIGKILL [startup+300 s] /proc/loadavg: 1.00 1.00 0.98 2/54 14155 /proc/meminfo: memFree=204456/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=278284 CPUtime=296 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 63364 412 0 0 29585 15 0 0 20 0 1 0 7422693 284962816 47346 18446744073709551615 4194304 6763684 140736915969280 140736915911400 140506661240568 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69571 47346 1073 628 0 46124 0 Current children cumulated CPU time (s) 296 Current children cumulated vsize (KiB) 278284 Sending Terminated to process tree (bottom up) Sleeping 2 seconds Solver just ended. Dumping a history of the last processes samples [startup+300 s] /proc/loadavg: 1.00 1.00 0.98 2/54 14155 /proc/meminfo: memFree=204456/1022884 swapFree=0/0 [pid=13923] ppid=13922 vsize=278284 CPUtime=296 /proc/13923/stat : 13923 (smart) R 13922 13923 2806 34818 2806 4202496 63364 412 0 0 29585 15 0 0 20 0 1 0 7422693 284962816 47346 18446744073709551615 4194304 6763684 140736915969280 140736915911400 140506661240568 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/13923/statm: 69571 47346 1073 628 0 46124 0 Current children cumulated CPU time (s) 296 Current children cumulated vsize (KiB) 278284 Child ended because it received signal 15 (SIGTERM) Real time (s): 300.025 CPU time (s): 296.034 CPU user time (s): 295.866 CPU system time (s): 0.16801 CPU usage (%): 98.67 Max. virtual memory (cumulated for all children) (KiB): 278284 getrusage(RUSAGE_CHILDREN,...) data: user time used= 295.866 system time used= 0.16801 maximum resident set size= 189384 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 63776 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= 7 involuntary context switches= 5428 runsolver used 0.32002 second user time and 0.816051 second system time The end