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/29.runsolver.aptitude aptitude -s -y --without-recommends install curl rmagic gnomeicu-common libxml-stream-perl liblablgl-ocaml 

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.93 0.44 0.17 2/55 19477
/proc/meminfo: memFree=248080/1022884 swapFree=0/0
[pid=19477] ppid=19476 vsize=3152 CPUtime=0
/proc/19477/stat : 19477 (runsolver) R 19476 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28179156 3227648 32 18446744073709551615 134512640 134586868 4287749600 4287747648 4151759920 0 0 0 24578 0 0 0 17 0 0 0 0 0 0
/proc/19477/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.181507 s]
/proc/loadavg: 0.93 0.44 0.17 2/55 19477
/proc/meminfo: memFree=248080/1022884 swapFree=0/0
[pid=19477] ppid=19476 vsize=86100 CPUtime=0.16
/proc/19477/stat : 19477 (aptitude) R 19476 19477 17863 34816 17863 4202496 7114 1708 0 0 14 2 0 0 20 0 1 0 28179156 88166400 6904 18446744073709551615 139913650995200 139913655302552 140736488232528 140736488221672 139913645676848 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/19477/statm: 21525 6904 4716 1052 0 2116 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 86100

[startup+0.200532 s]
/proc/loadavg: 0.93 0.44 0.17 2/55 19477
/proc/meminfo: memFree=248080/1022884 swapFree=0/0
[pid=19477] ppid=19476 vsize=89348 CPUtime=0.18
/proc/19477/stat : 19477 (aptitude) R 19476 19477 17863 34816 17863 4202496 8301 1708 0 0 16 2 0 0 20 0 1 0 28179156 91492352 7346 18446744073709551615 139913650995200 139913655302552 140736488232528 140736488222040 139913608876311 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0
/proc/19477/statm: 22337 7346 4721 1052 0 2928 0
Current children cumulated CPU time (s) 0.18
Current children cumulated vsize (KiB) 89348

[startup+0.300276 s]
/proc/loadavg: 0.93 0.44 0.17 2/55 19477
/proc/meminfo: memFree=248080/1022884 swapFree=0/0
[pid=19477] ppid=19476 vsize=96684 CPUtime=0.28
/proc/19477/stat : 19477 (aptitude) R 19476 19477 17863 34816 17863 4202496 9018 1708 0 0 25 3 0 0 20 0 2 0 28179156 99004416 7653 18446744073709551615 139913650995200 139913655302552 140736488232528 140736488228312 139913646395409 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19477/statm: 24171 7653 4887 1052 0 4762 0
Current children cumulated CPU time (s) 0.28
Current children cumulated vsize (KiB) 96684

[startup+0.700215 s]
/proc/loadavg: 0.93 0.44 0.17 2/55 19477
/proc/meminfo: memFree=248080/1022884 swapFree=0/0
[pid=19477] ppid=19476 vsize=100644 CPUtime=0.68
/proc/19477/stat : 19477 (aptitude) R 19476 19477 17863 34816 17863 4202496 10126 1708 0 0 65 3 0 0 20 0 2 0 28179156 103059456 8756 18446744073709551615 139913650995200 139913655302552 140736488232528 140736488220328 139913608490910 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19477/statm: 25161 8756 4994 1052 0 5752 0
Current children cumulated CPU time (s) 0.68
Current children cumulated vsize (KiB) 100644

[startup+1.50026 s]
/proc/loadavg: 0.93 0.44 0.17 2/57 19483
/proc/meminfo: memFree=232316/1022884 swapFree=0/0
[pid=19477] ppid=19476 vsize=107516 CPUtime=1.48
/proc/19477/stat : 19477 (aptitude) R 19476 19477 17863 34816 17863 4202496 14122 2207 0 0 142 6 0 0 20 0 2 0 28179156 110096384 10638 18446744073709551615 139913650995200 139913655302552 140736488232528 140736488222288 139913608698166 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19477/statm: 26879 10638 5157 1052 0 7463 0
[pid=19477/tid=19482] ppid=19476 vsize=107516 CPUtime=0.17
/proc/19477/task/19482/stat : 19482 (aptitude) S 19476 19477 17863 34816 17863 4202560 1990 2207 0 0 16 1 0 0 20 0 2 0 28179186 110096384 10638 18446744073709551615 139913650995200 139913655302552 140736488232528 139913567574016 139913619739348 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) 107516

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

[startup+1.50026 s]
/proc/loadavg: 0.93 0.44 0.17 2/57 19483
/proc/meminfo: memFree=232316/1022884 swapFree=0/0
[pid=19477] ppid=19476 vsize=107516 CPUtime=1.48
/proc/19477/stat : 19477 (aptitude) R 19476 19477 17863 34816 17863 4202496 14122 2207 0 0 142 6 0 0 20 0 2 0 28179156 110096384 10638 18446744073709551615 139913650995200 139913655302552 140736488232528 140736488222288 139913608698166 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19477/statm: 26879 10638 5157 1052 0 7463 0
[pid=19477/tid=19482] ppid=19476 vsize=107516 CPUtime=0.17
/proc/19477/task/19482/stat : 19482 (aptitude) S 19476 19477 17863 34816 17863 4202560 1990 2207 0 0 16 1 0 0 20 0 2 0 28179186 110096384 10638 18446744073709551615 139913650995200 139913655302552 140736488232528 139913567574016 139913619739348 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) 107516

Child status: 0
Real time (s): 1.53059
CPU time (s): 1.52809
CPU user time (s): 1.43609
CPU system time (s): 0.092005
CPU usage (%): 99.8368
Max. virtual memory (cumulated for all children) (KiB): 107516

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.43609
system time used= 0.092005
maximum resident set size= 42564
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 17060
page faults= 0
swaps= 0
block input operations= 0
block output operations= 24
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 60
involuntary context switches= 73

runsolver used 0.004 second user time and 0.008 second system time

The end