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/156.runsolver.aptitude aptitude -s -y --without-recommends remove cpio libasound2 ncurses-base libgpgme11 libgcrypt11-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: 1.12 0.96 0.56 2/55 20737
/proc/meminfo: memFree=937364/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=54860 CPUtime=0
/proc/20737/stat : 20737 (aptitude) R 20736 20737 17863 34816 17863 4202496 594 0 0 0 0 0 0 0 20 0 1 0 28239907 56176640 494 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414729256 139883395577785 0 0 0 0 0 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 13715 494 404 1052 0 73 0

[startup+0.155809 s]
/proc/loadavg: 1.12 0.96 0.56 2/55 20737
/proc/meminfo: memFree=937364/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=86100 CPUtime=0.14
/proc/20737/stat : 20737 (aptitude) R 20736 20737 17863 34816 17863 4202496 7107 1707 0 0 12 2 0 0 20 0 1 0 28239907 88166400 6899 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414721696 139883399918144 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 21525 6899 4711 1052 0 2116 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 86100

[startup+0.200292 s]
/proc/loadavg: 1.12 0.96 0.56 2/55 20737
/proc/meminfo: memFree=937364/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=89348 CPUtime=0.18
/proc/20737/stat : 20737 (aptitude) R 20736 20737 17863 34816 17863 4202496 8316 1707 0 0 16 2 0 0 20 0 1 0 28239907 91492352 7362 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414719560 139883400705951 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 22337 7362 4721 1052 0 2928 0
Current children cumulated CPU time (s) 0.18
Current children cumulated vsize (KiB) 89348

[startup+0.300261 s]
/proc/loadavg: 1.12 0.96 0.56 2/55 20737
/proc/meminfo: memFree=937364/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=96684 CPUtime=0.29
/proc/20737/stat : 20737 (aptitude) R 20736 20737 17863 34816 17863 4202496 9018 1707 0 0 26 3 0 0 20 0 2 0 28239907 99004416 7652 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414725640 139883392583796 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 24171 7652 4886 1052 0 4762 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 96684

[startup+0.700208 s]
/proc/loadavg: 1.12 0.96 0.56 2/55 20737
/proc/meminfo: memFree=937364/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=100468 CPUtime=0.69
/proc/20737/stat : 20737 (aptitude) R 20736 20737 17863 34816 17863 4202496 10065 1707 0 0 66 3 0 0 20 0 2 0 28239907 102879232 8695 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414720512 139883392594928 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 25117 8695 4977 1052 0 5708 0
Current children cumulated CPU time (s) 0.69
Current children cumulated vsize (KiB) 100468

[startup+1.50024 s]
/proc/loadavg: 1.12 0.96 0.56 2/57 20742
/proc/meminfo: memFree=921732/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=112708 CPUtime=1.48
/proc/20737/stat : 20737 (aptitude) S 20736 20737 17863 34816 17863 4202496 13224 1707 0 0 144 4 0 0 20 0 2 0 28239907 115412992 11853 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414721808 139883366512203 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 28177 11853 5068 1052 0 8768 0
[pid=20737/tid=20742] ppid=20736 vsize=112708 CPUtime=0.37
/proc/20737/task/20742/stat : 20742 (aptitude) R 20736 20737 17863 34816 17863 4202560 3066 1707 0 0 36 1 0 0 20 0 2 0 28239937 115412992 11853 18446744073709551615 139883397767168 139883402074520 140735414730048 139883314336232 139883400639162 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 112708

Solver just ended. Dumping a history of the last processes samples

[startup+1.60034 s]
/proc/loadavg: 1.12 0.96 0.56 2/57 20742
/proc/meminfo: memFree=921732/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=113500 CPUtime=1.58
/proc/20737/stat : 20737 (aptitude) S 20736 20737 17863 34816 17863 4202496 13426 1707 0 0 154 4 0 0 20 0 2 0 28239907 116224000 12055 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414721808 139883366512203 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 28375 12055 5068 1052 0 8966 0
[pid=20737/tid=20742] ppid=20736 vsize=113500 CPUtime=0.47
/proc/20737/task/20742/stat : 20742 (aptitude) R 20736 20737 17863 34816 17863 4202560 3268 1707 0 0 46 1 0 0 20 0 2 0 28239937 116224000 12055 18446744073709551615 139883397767168 139883402074520 140735414730048 139883314336232 139883392590969 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.58
Current children cumulated vsize (KiB) 113500

[startup+1.80025 s]
/proc/loadavg: 1.12 0.96 0.56 2/57 20742
/proc/meminfo: memFree=921732/1022884 swapFree=0/0
[pid=20737] ppid=20736 vsize=181044 CPUtime=1.77
/proc/20737/stat : 20737 (aptitude) R 20736 20737 17863 34816 17863 4202496 14099 1707 0 0 173 4 0 0 20 0 2 0 28239907 185389056 12699 18446744073709551615 139883397767168 139883402074520 140735414730048 140735414721816 139883392684144 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/20737/statm: 45261 12699 5120 1052 0 25845 0
[pid=20737/tid=20742] ppid=20736 vsize=181044 CPUtime=0.57
/proc/20737/task/20742/stat : 20742 (aptitude) S 20736 20737 17863 34816 17863 4202560 3758 1707 0 0 55 2 0 0 20 0 2 0 28239937 185389056 12699 18446744073709551615 139883397767168 139883402074520 140735414730048 139883314345984 139883366511316 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.77
Current children cumulated vsize (KiB) 181044

Child status: 255
Real time (s): 1.84654
CPU time (s): 1.82811
CPU user time (s): 1.75611
CPU system time (s): 0.072004
CPU usage (%): 99.0019
Max. virtual memory (cumulated for all children) (KiB): 181044

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.75611
system time used= 0.072004
maximum resident set size= 50836
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 15898
page faults= 3
swaps= 0
block input operations= 520
block output operations= 40
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 59
involuntary context switches= 85

runsolver used 0.004 second user time and 0.008 second system time

The end