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/141.runsolver.aptitude aptitude -s -y --without-recommends remove gsfonts nautilus-cd-burner telnet ppp libarts1-audiofile 

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: 1.00 1.01 1.00 2/55 22495
/proc/meminfo: memFree=903728/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=3152 CPUtime=0
/proc/22495/stat : 22495 (runsolver) R 22494 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28697358 3227648 32 18446744073709551615 134512640 134586868 4291109408 4291107456 4151858224 0 0 0 24578 0 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.199212 s]
/proc/loadavg: 1.00 1.01 1.00 2/55 22495
/proc/meminfo: memFree=903728/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=89152 CPUtime=0.19
/proc/22495/stat : 22495 (aptitude) R 22494 22495 17863 34816 17863 4202496 7869 1708 0 0 17 2 0 0 20 0 1 0 28697358 91291648 7662 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666326080 140291646212066 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 22288 7662 6726 1052 0 858 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 89152

[startup+0.200273 s]
/proc/loadavg: 1.00 1.01 1.00 2/55 22495
/proc/meminfo: memFree=903728/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=89152 CPUtime=0.19
/proc/22495/stat : 22495 (aptitude) R 22494 22495 17863 34816 17863 4202496 7869 1708 0 0 17 2 0 0 20 0 1 0 28697358 91291648 7662 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666326080 140291608940270 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 22288 7662 6726 1052 0 858 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 89152

[startup+0.300207 s]
/proc/loadavg: 1.00 1.01 1.00 2/55 22495
/proc/meminfo: memFree=903728/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=101864 CPUtime=0.28
/proc/22495/stat : 22495 (aptitude) R 22494 22495 17863 34816 17863 4202496 11708 1708 0 0 26 2 0 0 20 0 1 0 28697358 104308736 10756 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666325736 140291646259316 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 25466 10756 6746 1052 0 4036 0
Current children cumulated CPU time (s) 0.28
Current children cumulated vsize (KiB) 101864

[startup+0.700204 s]
/proc/loadavg: 1.00 1.01 1.00 2/55 22495
/proc/meminfo: memFree=903728/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=113868 CPUtime=0.68
/proc/22495/stat : 22495 (aptitude) R 22494 22495 17863 34816 17863 4202496 13631 1708 0 0 64 4 0 0 20 0 2 0 28697358 116600832 12003 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666327576 140291646182521 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 28467 12003 6964 1052 0 7037 0
Current children cumulated CPU time (s) 0.68
Current children cumulated vsize (KiB) 113868

[startup+1.50024 s]
/proc/loadavg: 1.00 1.01 1.00 2/57 22500
/proc/meminfo: memFree=883260/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=115236 CPUtime=1.48
/proc/22495/stat : 22495 (aptitude) R 22494 22495 17863 34816 17863 4202496 13835 1708 0 0 144 4 0 0 20 0 2 0 28697358 118001664 12205 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666323008 140291608858994 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 28809 12205 7033 1052 0 7379 0
[pid=22495/tid=22500] ppid=22494 vsize=115236 CPUtime=0
/proc/22495/task/22500/stat : 22500 (aptitude) S 22494 22495 17863 34816 17863 4202560 4 1708 0 0 0 0 0 0 20 0 2 0 28697403 118001664 12205 18446744073709551615 140291651358720 140291655666072 140736666336304 140291554764800 140291620102868 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) 115236

[startup+3.10031 s]
/proc/loadavg: 1.00 1.01 1.00 2/57 22500
/proc/meminfo: memFree=872720/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=200572 CPUtime=3.07
/proc/22495/stat : 22495 (aptitude) S 22494 22495 17863 34816 17863 4202496 19075 1708 0 0 302 5 0 0 20 0 2 0 28697358 205385728 17444 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666328064 140291620103755 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 50143 17444 7092 1052 0 28713 0
[pid=22495/tid=22500] ppid=22494 vsize=200572 CPUtime=1.37
/proc/22495/task/22500/stat : 22500 (aptitude) R 22494 22495 17863 34816 17863 4202560 5238 1708 0 0 136 1 0 0 20 0 2 0 28697403 205385728 17444 18446744073709551615 140291651358720 140291655666072 140736666336304 140291554756472 140291609511159 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.07
Current children cumulated vsize (KiB) 200572

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

[startup+3.20032 s]
/proc/loadavg: 1.00 1.01 1.00 2/57 22500
/proc/meminfo: memFree=872720/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=201232 CPUtime=3.17
/proc/22495/stat : 22495 (aptitude) S 22494 22495 17863 34816 17863 4202496 19225 1708 0 0 312 5 0 0 20 0 2 0 28697358 206061568 17594 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666328064 140291620103755 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 50308 17594 7092 1052 0 28878 0
[pid=22495/tid=22500] ppid=22494 vsize=201232 CPUtime=1.47
/proc/22495/task/22500/stat : 22500 (aptitude) R 22494 22495 17863 34816 17863 4202560 5388 1708 0 0 146 1 0 0 20 0 2 0 28697403 206061568 17594 18446744073709551615 140291651358720 140291655666072 140736666336304 140291554759160 140291608869000 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.17
Current children cumulated vsize (KiB) 201232

[startup+3.40318 s]
/proc/loadavg: 1.00 1.01 1.00 2/57 22500
/proc/meminfo: memFree=860568/1022884 swapFree=0/0
[pid=22495] ppid=22494 vsize=202184 CPUtime=3.37
/proc/22495/stat : 22495 (aptitude) R 22494 22495 17863 34816 17863 4202496 19516 1708 0 0 332 5 0 0 20 0 2 0 28697358 207036416 17883 18446744073709551615 140291651358720 140291655666072 140736666336304 140736666324168 140291653563640 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/22495/statm: 50546 17883 7141 1052 0 29109 0
[pid=22495/tid=22500] ppid=22494 vsize=202184 CPUtime=1.54
/proc/22495/task/22500/stat : 22500 (aptitude) S 22494 22495 17863 34816 17863 4202560 5620 1708 0 0 153 1 0 0 20 0 2 0 28697403 207036416 17883 18446744073709551615 140291651358720 140291655666072 140736666336304 140291554764800 140291620102868 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.37
Current children cumulated vsize (KiB) 202184

Child status: 0
Real time (s): 3.46276
CPU time (s): 3.44822
CPU user time (s): 3.36421
CPU system time (s): 0.084005
CPU usage (%): 99.58
Max. virtual memory (cumulated for all children) (KiB): 202184

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.36421
system time used= 0.084005
maximum resident set size= 71864
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 21379
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= 58
involuntary context switches= 107

runsolver used 0.008 second user time and 0.012 second system time

The end