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-squeeze-sid/logs/42.runsolver.smart smart --config-file=/home/cbse/var/lib/smart/config install gstreamer0.8-jack g77-2.95-doc upx-ucl libginac1.3 ted-gtk 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.98 0.98 2/53 26645 /proc/meminfo: memFree=391768/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=26808 CPUtime=0 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 604 0 0 0 0 0 0 0 20 0 1 0 15495683 27451392 495 18446744073709551615 4194304 6763684 140733674736128 140733674726664 4411810 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 6702 495 367 628 0 161 0 [startup+0.177112 s] /proc/loadavg: 0.99 0.98 0.98 2/53 26645 /proc/meminfo: memFree=391768/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=134320 CPUtime=0.16 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 13163 0 0 0 12 4 0 0 20 0 1 0 15495683 137543680 11882 18446744073709551615 4194304 6763684 140733674736128 140733674730840 139776244739581 0 0 16781312 2 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 33580 11882 1043 628 0 11163 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 134320 [startup+0.200252 s] /proc/loadavg: 0.99 0.98 0.98 2/53 26645 /proc/meminfo: memFree=391768/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=132076 CPUtime=0.18 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 14573 0 0 0 14 4 0 0 20 0 1 0 15495683 135245824 11755 18446744073709551615 4194304 6763684 140733674736128 140733674731144 139776263562912 0 0 16781312 2 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 33019 11755 1043 628 0 10602 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 132076 [startup+0.300236 s] /proc/loadavg: 0.99 0.98 0.98 2/53 26645 /proc/meminfo: memFree=391768/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=136216 CPUtime=0.28 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 21079 412 0 0 21 7 0 0 20 0 1 0 15495683 139485184 11828 18446744073709551615 4194304 6763684 140733674736128 140733674732104 5763084 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 34054 11828 1058 628 0 10607 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 136216 [startup+0.700198 s] /proc/loadavg: 0.99 0.98 0.98 2/53 26645 /proc/meminfo: memFree=391768/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=185428 CPUtime=0.69 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 35381 412 0 0 58 11 0 0 20 0 1 0 15495683 189878272 24103 18446744073709551615 4194304 6763684 140733674736128 140733674732120 5727865 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 46357 24103 1059 628 0 22910 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 185428 [startup+1.50018 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=249904/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=289644 CPUtime=1.48 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 67587 412 0 0 129 19 0 0 20 0 1 0 15495683 296595456 50157 18446744073709551615 4194304 6763684 140733674736128 140733674732184 5511983 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 72411 50157 1059 628 0 48964 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 289644 [startup+3.10019 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=127640/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=347204 CPUtime=3.08 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 94303 412 0 0 283 25 0 0 20 0 1 0 15495683 355536896 64552 18446744073709551615 4194304 6763684 140733674736128 140733674732568 5743560 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 86801 64552 1068 628 0 63354 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 347204 [startup+6.30019 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=118712/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=365568 CPUtime=6.27 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 98907 412 0 0 601 26 0 0 20 0 1 0 15495683 374341632 69145 18446744073709551615 4194304 6763684 140733674736128 140733674733080 139776227569345 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91392 69145 1073 628 0 67945 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 365568 [startup+12.7002 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=118588/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=365568 CPUtime=12.64 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 98913 412 0 0 1238 26 0 0 20 0 1 0 15495683 374341632 69145 18446744073709551615 4194304 6763684 140733674736128 140733674733080 139776227569345 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91392 69145 1073 628 0 67945 0 Current children cumulated CPU time (s) 12.64 Current children cumulated vsize (KiB) 365568 [startup+25.5002 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=118588/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=365568 CPUtime=25.39 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 98913 412 0 0 2513 26 0 0 20 0 1 0 15495683 374341632 69145 18446744073709551615 4194304 6763684 140733674736128 140733674733080 139776245317358 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91392 69145 1073 628 0 67945 0 Current children cumulated CPU time (s) 25.39 Current children cumulated vsize (KiB) 365568 [startup+51.1002 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=118588/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=365568 CPUtime=50.9 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 98915 412 0 0 5064 26 0 0 20 0 1 0 15495683 374341632 69145 18446744073709551615 4194304 6763684 140733674736128 140733674733080 139776245317362 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91392 69145 1073 628 0 67945 0 Current children cumulated CPU time (s) 50.9 Current children cumulated vsize (KiB) 365568 [startup+102.3 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=118464/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=365568 CPUtime=101.91 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 98917 412 0 0 10165 26 0 0 20 0 1 0 15495683 374341632 69145 18446744073709551615 4194304 6763684 140733674736128 140733674733080 139776245319180 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91392 69145 1073 628 0 67945 0 Current children cumulated CPU time (s) 101.91 Current children cumulated vsize (KiB) 365568 [startup+162.3 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=118464/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=365568 CPUtime=161.68 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 98918 412 0 0 16142 26 0 0 20 0 1 0 15495683 374341632 69145 18446744073709551615 4194304 6763684 140733674736128 140733674733080 139776245317338 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91392 69145 1073 628 0 67945 0 Current children cumulated CPU time (s) 161.68 Current children cumulated vsize (KiB) 365568 [startup+222.303 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=118464/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=365568 CPUtime=221.45 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 98918 412 0 0 22119 26 0 0 20 0 1 0 15495683 374341632 69145 18446744073709551615 4194304 6763684 140733674736128 140733674733080 139776245317338 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91392 69145 1073 628 0 67945 0 Current children cumulated CPU time (s) 221.45 Current children cumulated vsize (KiB) 365568 [startup+282.3 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=116604/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=367392 CPUtime=281.23 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 99399 412 0 0 28097 26 0 0 20 0 1 0 15495683 376209408 69625 18446744073709551615 4194304 6763684 140733674736128 140733674635144 139776227569345 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91848 69625 1073 628 0 68401 0 Current children cumulated CPU time (s) 281.23 Current children cumulated vsize (KiB) 367392 Maximum wall clock time exceeded: sending signal-name then SIGKILL [startup+300 s] /proc/loadavg: 0.99 0.98 0.98 2/54 26648 /proc/meminfo: memFree=116604/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=367392 CPUtime=298.86 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 99399 412 0 0 29860 26 0 0 20 0 1 0 15495683 376209408 69625 18446744073709551615 4194304 6763684 140733674736128 140733674635144 139776227569312 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91848 69625 1073 628 0 68401 0 Current children cumulated CPU time (s) 298.86 Current children cumulated vsize (KiB) 367392 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.98 2/54 26648 /proc/meminfo: memFree=116604/1022884 swapFree=0/0 [pid=26645] ppid=26644 vsize=367392 CPUtime=298.86 /proc/26645/stat : 26645 (smart) R 26644 26645 2806 34818 2806 4202496 99399 412 0 0 29860 26 0 0 20 0 1 0 15495683 376209408 69625 18446744073709551615 4194304 6763684 140733674736128 140733674635144 139776227569312 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/26645/statm: 91848 69625 1073 628 0 68401 0 Current children cumulated CPU time (s) 298.86 Current children cumulated vsize (KiB) 367392 Child ended because it received signal 15 (SIGTERM) Real time (s): 300.024 CPU time (s): 298.891 CPU user time (s): 298.611 CPU system time (s): 0.280017 CPU usage (%): 99.6222 Max. virtual memory (cumulated for all children) (KiB): 367392 getrusage(RUSAGE_CHILDREN,...) data: user time used= 298.611 system time used= 0.280017 maximum resident set size= 278500 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 99811 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= 4448 runsolver used 0 second user time and 1.13207 second system time The end