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/86.runsolver.smart smart --config-file=/home/cbse/var/lib/smart/config install libxi-dev dict-freedict-nld-deu ftdi-eeprom libdmalloc4-dev vdr-plugin-sky 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.99 0.94 2/53 6858 /proc/meminfo: memFree=451740/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=26808 CPUtime=0 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 607 0 0 0 0 0 0 0 20 0 1 0 2958925 27451392 498 18446744073709551615 4194304 6763684 140735420446048 140735420436584 139981268837983 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 6702 498 369 628 0 161 0 [startup+0.168348 s] /proc/loadavg: 0.99 0.99 0.94 2/53 6858 /proc/meminfo: memFree=451740/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=118376 CPUtime=0.15 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 11186 412 0 0 11 4 0 0 20 0 1 0 2958925 121217024 7349 18446744073709551615 4194304 6763684 140735420446048 140735420442040 5763084 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 29594 7349 1058 628 0 6147 0 Current children cumulated CPU time (s) 0.15 Current children cumulated vsize (KiB) 118376 [startup+0.200251 s] /proc/loadavg: 0.99 0.99 0.94 2/53 6858 /proc/meminfo: memFree=451740/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=119656 CPUtime=0.18 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 13422 412 0 0 13 5 0 0 20 0 1 0 2958925 122527744 7645 18446744073709551615 4194304 6763684 140735420446048 140735420442104 5511600 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 29914 7645 1058 628 0 6467 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 119656 [startup+0.300259 s] /proc/loadavg: 0.99 0.99 0.94 2/53 6858 /proc/meminfo: memFree=451740/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=134016 CPUtime=0.28 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 16999 412 0 0 22 6 0 0 20 0 1 0 2958925 137232384 11219 18446744073709551615 4194304 6763684 140735420446048 140735420442104 5764419 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 33504 11219 1059 628 0 10057 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 134016 [startup+0.700199 s] /proc/loadavg: 0.99 0.99 0.94 2/53 6858 /proc/meminfo: memFree=451740/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=195812 CPUtime=0.68 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 35528 412 0 0 56 12 0 0 20 0 1 0 2958925 200511488 26662 18446744073709551615 4194304 6763684 140735420446048 140735420442104 5727865 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 48953 26662 1059 628 0 25506 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 195812 [startup+1.50019 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6861 /proc/meminfo: memFree=338520/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=1.48 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44750 412 0 0 133 15 0 0 20 0 1 0 2958925 212766720 29707 18446744073709551615 4194304 6763684 140735420446048 140735420441184 5763184 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29707 1069 628 0 28498 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 207780 [startup+3.10019 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6861 /proc/meminfo: memFree=336908/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=3.08 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 293 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981268807416 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 207780 [startup+6.30019 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6861 /proc/meminfo: memFree=336908/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=6.27 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 612 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 5155719 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 207780 [startup+12.7002 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6861 /proc/meminfo: memFree=336660/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=12.64 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 1249 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 4628480 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 12.64 Current children cumulated vsize (KiB) 207780 [startup+25.5002 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6861 /proc/meminfo: memFree=336660/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=25.39 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 2524 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981251059393 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 25.39 Current children cumulated vsize (KiB) 207780 [startup+51.1002 s] /proc/loadavg: 0.99 0.99 0.94 2/58 6884 /proc/meminfo: memFree=333504/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=50.82 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 5067 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981268807386 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 50.82 Current children cumulated vsize (KiB) 207780 [startup+102.3 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6886 /proc/meminfo: memFree=336140/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=101.83 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 10168 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981251059393 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 101.83 Current children cumulated vsize (KiB) 207780 [startup+162.3 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6886 /proc/meminfo: memFree=336140/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=161.61 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 16146 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981268809228 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 161.61 Current children cumulated vsize (KiB) 207780 [startup+222.303 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6886 /proc/meminfo: memFree=336140/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=221.39 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 22124 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981268807520 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 221.39 Current children cumulated vsize (KiB) 207780 [startup+282.3 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6886 /proc/meminfo: memFree=336140/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=281.17 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 28102 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981268807386 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 281.17 Current children cumulated vsize (KiB) 207780 Maximum wall clock time exceeded: sending signal-name then SIGKILL [startup+300 s] /proc/loadavg: 0.99 0.99 0.94 2/54 6886 /proc/meminfo: memFree=336140/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=298.8 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 29865 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981268807386 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 298.8 Current children cumulated vsize (KiB) 207780 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.99 0.94 2/54 6886 /proc/meminfo: memFree=336140/1022884 swapFree=0/0 [pid=6858] ppid=6857 vsize=207780 CPUtime=298.8 /proc/6858/stat : 6858 (smart) R 6857 6858 2806 34818 2806 4202496 44762 412 0 0 29865 15 0 0 20 0 1 0 2958925 212766720 29710 18446744073709551615 4194304 6763684 140735420446048 140735420443000 139981268807386 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/6858/statm: 51945 29710 1072 628 0 28498 0 Current children cumulated CPU time (s) 298.8 Current children cumulated vsize (KiB) 207780 Child ended because it received signal 15 (SIGTERM) Real time (s): 300.014 CPU time (s): 298.823 CPU user time (s): 298.659 CPU system time (s): 0.16401 CPU usage (%): 99.6029 Max. virtual memory (cumulated for all children) (KiB): 207780 getrusage(RUSAGE_CHILDREN,...) data: user time used= 298.659 system time used= 0.16401 maximum resident set size= 120000 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 45174 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= 4453 runsolver used 0.392024 second user time and 0.716044 second system time The end