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/logs/114.runsolver.smart smart --config-file=/home/cbse/var/lib/smart/config remove kwin librsvg2-common kmix xmms totem 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 [startup+0 s] /proc/loadavg: 0.99 0.98 0.94 2/53 7767 /proc/meminfo: memFree=448808/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=3152 CPUtime=0 /proc/7767/stat : 7767 (runsolver) R 7766 2806 2806 34818 2806 4202560 0 0 0 0 0 0 0 0 20 0 1 0 3607294 3227648 33 18446744073709551615 134512640 134586868 4286691040 4286689088 4151604272 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.131666 s] /proc/loadavg: 0.99 0.98 0.94 2/53 7767 /proc/meminfo: memFree=448808/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=107500 CPUtime=0.12 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 8895 414 0 0 9 3 0 0 20 0 1 0 3607294 110080000 5605 18446744073709551615 4194304 6763684 140734163851920 140734163840984 139636740600306 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 26875 5605 1052 628 0 4458 0 Current children cumulated CPU time (s) 0.12 Current children cumulated vsize (KiB) 107500 [startup+0.200235 s] /proc/loadavg: 0.99 0.98 0.94 2/53 7767 /proc/meminfo: memFree=448808/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=120420 CPUtime=0.19 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 13639 414 0 0 15 4 0 0 20 0 1 0 3607294 123310080 7861 18446744073709551615 4194304 6763684 140734163851920 140734163847912 139636759467680 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 30105 7861 1059 628 0 6658 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 120420 [startup+0.300235 s] /proc/loadavg: 0.99 0.98 0.94 2/53 7767 /proc/meminfo: memFree=448808/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=135440 CPUtime=0.28 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 17381 414 0 0 24 4 0 0 20 0 1 0 3607294 138690560 11602 18446744073709551615 4194304 6763684 140734163851920 140734163847848 5727809 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 33860 11602 1059 628 0 10413 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 135440 [startup+0.700187 s] /proc/loadavg: 0.99 0.98 0.94 2/53 7767 /proc/meminfo: memFree=448808/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=199848 CPUtime=0.69 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 36538 414 0 0 61 8 0 0 20 0 1 0 3607294 204644352 27673 18446744073709551615 4194304 6763684 140734163851920 140734163847464 4926805 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 49962 27673 1059 628 0 26515 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 199848 [startup+1.5002 s] /proc/loadavg: 0.99 0.98 0.94 2/54 7770 /proc/meminfo: memFree=335472/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=207776 CPUtime=1.48 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 44750 414 0 0 138 10 0 0 20 0 1 0 3607294 212762624 29707 18446744073709551615 4194304 6763684 140734163851920 140734163847056 4414165 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 51944 29707 1069 628 0 28497 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 207776 [startup+3.10018 s] /proc/loadavg: 0.99 0.98 0.94 2/54 7770 /proc/meminfo: memFree=333860/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=207776 CPUtime=3.08 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 44763 414 0 0 298 10 0 0 20 0 1 0 3607294 212762624 29711 18446744073709551615 4194304 6763684 140734163851920 140734163848872 139636741223948 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 51944 29711 1073 628 0 28497 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 207776 [startup+6.30018 s] /proc/loadavg: 0.99 0.98 0.94 2/54 7770 /proc/meminfo: memFree=333852/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=207776 CPUtime=6.27 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 44763 414 0 0 617 10 0 0 20 0 1 0 3607294 212762624 29711 18446744073709551615 4194304 6763684 140734163851920 140734163848872 5221400 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 51944 29711 1073 628 0 28497 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 207776 [startup+12.7002 s] /proc/loadavg: 0.99 0.98 0.94 2/54 7770 /proc/meminfo: memFree=333728/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=207776 CPUtime=12.64 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 44763 414 0 0 1254 10 0 0 20 0 1 0 3607294 212762624 29711 18446744073709551615 4194304 6763684 140734163851920 140734163848872 139636741222106 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 51944 29711 1073 628 0 28497 0 Current children cumulated CPU time (s) 12.64 Current children cumulated vsize (KiB) 207776 [startup+25.5002 s] /proc/loadavg: 0.99 0.98 0.94 2/54 7770 /proc/meminfo: memFree=332984/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=208544 CPUtime=25.39 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 44979 414 0 0 2529 10 0 0 20 0 1 0 3607294 213549056 29927 18446744073709551615 4194304 6763684 140734163851920 140734163842616 139636741222257 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 52136 29927 1073 628 0 28689 0 Current children cumulated CPU time (s) 25.39 Current children cumulated vsize (KiB) 208544 [startup+51.1002 s] /proc/loadavg: 0.99 0.98 0.94 2/54 7770 /proc/meminfo: memFree=327032/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=214356 CPUtime=50.9 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 46420 414 0 0 5079 11 0 0 20 0 1 0 3607294 219500544 31368 18446744073709551615 4194304 6763684 140734163851920 140734163834888 139636741223952 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 53589 31368 1073 628 0 30142 0 Current children cumulated CPU time (s) 50.9 Current children cumulated vsize (KiB) 214356 [startup+102.3 s] /proc/loadavg: 0.99 0.98 0.94 2/54 7778 /proc/meminfo: memFree=326536/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=214356 CPUtime=101.9 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 46420 414 0 0 10179 11 0 0 20 0 1 0 3607294 219500544 31368 18446744073709551615 4194304 6763684 140734163851920 140734163834888 139636741222122 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 53589 31368 1073 628 0 30142 0 Current children cumulated CPU time (s) 101.9 Current children cumulated vsize (KiB) 214356 [startup+162.3 s] /proc/loadavg: 0.99 0.98 0.94 2/54 8007 /proc/meminfo: memFree=326536/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=214356 CPUtime=158.82 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 46420 414 0 0 15870 12 0 0 20 0 1 0 3607294 219500544 31368 18446744073709551615 4194304 6763684 140734163851920 140734163834888 139636741225780 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 53589 31368 1073 628 0 30142 0 Current children cumulated CPU time (s) 158.82 Current children cumulated vsize (KiB) 214356 [startup+222.303 s] /proc/loadavg: 0.99 0.98 0.94 2/54 8007 /proc/meminfo: memFree=326536/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=214356 CPUtime=218.61 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 46420 414 0 0 21849 12 0 0 20 0 1 0 3607294 219500544 31368 18446744073709551615 4194304 6763684 140734163851920 140734163834888 139636741223944 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 53589 31368 1073 628 0 30142 0 Current children cumulated CPU time (s) 218.61 Current children cumulated vsize (KiB) 214356 [startup+282.3 s] /proc/loadavg: 0.99 0.98 0.94 2/54 8007 /proc/meminfo: memFree=326536/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=214356 CPUtime=278.4 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 46420 414 0 0 27828 12 0 0 20 0 1 0 3607294 219500544 31368 18446744073709551615 4194304 6763684 140734163851920 140734163834888 139636741222106 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 53589 31368 1073 628 0 30142 0 Current children cumulated CPU time (s) 278.4 Current children cumulated vsize (KiB) 214356 Maximum wall clock time exceeded: sending signal-name then SIGKILL [startup+300 s] /proc/loadavg: 0.99 0.98 0.94 2/54 8007 /proc/meminfo: memFree=326536/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=214356 CPUtime=296.04 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 46420 414 0 0 29592 12 0 0 20 0 1 0 3607294 219500544 31368 18446744073709551615 4194304 6763684 140734163851920 140734163834888 139636741222240 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 53589 31368 1073 628 0 30142 0 Current children cumulated CPU time (s) 296.04 Current children cumulated vsize (KiB) 214356 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: 0.99 0.98 0.94 2/54 8007 /proc/meminfo: memFree=326536/1022884 swapFree=0/0 [pid=7767] ppid=7766 vsize=214356 CPUtime=296.04 /proc/7767/stat : 7767 (smart) R 7766 7767 2806 34818 2806 4202496 46420 414 0 0 29592 12 0 0 20 0 1 0 3607294 219500544 31368 18446744073709551615 4194304 6763684 140734163851920 140734163834888 139636741222240 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/7767/statm: 53589 31368 1073 628 0 30142 0 Current children cumulated CPU time (s) 296.04 Current children cumulated vsize (KiB) 214356 Child ended because it received signal 15 (SIGTERM) Real time (s): 300.013 CPU time (s): 296.058 CPU user time (s): 295.926 CPU system time (s): 0.132008 CPU usage (%): 98.682 Max. virtual memory (cumulated for all children) (KiB): 214356 getrusage(RUSAGE_CHILDREN,...) data: user time used= 295.926 system time used= 0.132008 maximum resident set size= 125472 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 46834 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= 6 involuntary context switches= 5355 runsolver used 0.32402 second user time and 0.756047 second system time The end