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/152.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove kdbg libksieve0 libice-dev kwifimanager libart-2.0-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 [startup+0 s] /proc/loadavg: 0.99 0.98 0.92 2/55 29242 /proc/meminfo: memFree=311940/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=3152 CPUtime=0 /proc/29242/stat : 29242 (runsolver) R 29241 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28664009 3227648 33 18446744073709551615 134512640 134586868 4290525264 4290523312 4151657520 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.125424 s] /proc/loadavg: 0.99 0.98 0.92 2/55 29242 /proc/meminfo: memFree=311940/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=33508 CPUtime=0.13 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 1856 7199 0 0 6 1 5 1 20 0 1 0 28664009 34312192 1674 18446744073709551615 4194304 5184042 140733315153888 140733315151080 139883382522156 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 8377 1674 729 242 0 939 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 33508 [startup+0.200278 s] /proc/loadavg: 0.99 0.98 0.92 2/55 29242 /proc/meminfo: memFree=311940/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=35492 CPUtime=0.2 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 2326 7199 0 0 12 2 5 1 20 0 1 0 28664009 36343808 2143 18446744073709551615 4194304 5184042 140733315153888 140733315151080 139883398565024 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 8873 2143 729 242 0 1435 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 35492 [startup+0.300262 s] /proc/loadavg: 0.99 0.98 0.92 2/55 29242 /proc/meminfo: memFree=311940/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=47108 CPUtime=0.3 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 5355 7199 0 0 20 4 5 1 20 0 1 0 28664009 48238592 5164 18446744073709551615 4194304 5184042 140733315153888 140733315150088 139883398857281 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 11777 5164 835 242 0 4339 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 47108 [startup+0.700206 s] /proc/loadavg: 0.99 0.98 0.92 2/55 29242 /proc/meminfo: memFree=311940/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=58328 CPUtime=0.7 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 8205 7199 0 0 58 6 5 1 20 0 1 0 28664009 59727872 7916 18446744073709551615 4194304 5184042 140733315153888 140733315151320 139883398807944 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 14582 7916 842 242 0 7144 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 58328 [startup+1.50021 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=281684/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=60340 CPUtime=1.5 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 8871 7199 0 0 138 6 5 1 20 0 1 0 28664009 61788160 8453 18446744073709551615 4194304 5184042 140733315153888 140733315151192 139883391265793 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 15085 8453 842 242 0 7647 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 60340 [startup+3.10021 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=274616/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=69904 CPUtime=3.1 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 12338 7199 0 0 297 7 5 1 20 0 1 0 28664009 71581696 10376 18446744073709551615 4194304 5184042 140733315153888 140733315151192 139883399465475 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 17476 10376 842 242 0 10038 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 69904 [startup+6.30021 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=262588/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=79736 CPUtime=6.29 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 15197 7199 0 0 614 9 5 1 20 0 1 0 28664009 81649664 13235 18446744073709551615 4194304 5184042 140733315153888 140733315148184 139883398800384 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 19934 13235 842 242 0 12496 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 79736 [startup+12.7002 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=260108/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=83832 CPUtime=12.65 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 16802 7199 0 0 1250 9 5 1 20 0 1 0 28664009 85843968 13815 18446744073709551615 4194304 5184042 140733315153888 140733315148104 139883398800384 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 20958 13815 842 242 0 13520 0 Current children cumulated CPU time (s) 12.65 Current children cumulated vsize (KiB) 83832 Solver just ended. Dumping a history of the last processes samples [startup+12.8003 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=260108/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=83832 CPUtime=12.75 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 16810 7199 0 0 1260 9 5 1 20 0 1 0 28664009 85843968 13823 18446744073709551615 4194304 5184042 140733315153888 140733315148184 139883398800803 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 20958 13823 842 242 0 13520 0 Current children cumulated CPU time (s) 12.75 Current children cumulated vsize (KiB) 83832 [startup+14.4031 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=259364/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=83832 CPUtime=14.36 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 16980 7199 0 0 1420 10 5 1 20 0 1 0 28664009 85843968 13993 18446744073709551615 4194304 5184042 140733315153888 140733315148184 139883398883424 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 20958 13993 842 242 0 13520 0 Current children cumulated CPU time (s) 14.36 Current children cumulated vsize (KiB) 83832 [startup+16.0002 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=258744/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=83972 CPUtime=15.94 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 17189 7199 0 0 1578 10 5 1 20 0 1 0 28664009 85987328 14202 18446744073709551615 4194304 5184042 140733315153888 140733315147304 139883398809279 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 20993 14202 842 242 0 13555 0 Current children cumulated CPU time (s) 15.94 Current children cumulated vsize (KiB) 83972 [startup+16.8002 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=256636/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=86424 CPUtime=16.74 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 17873 7199 0 0 1658 10 5 1 20 0 1 0 28664009 88498176 14886 18446744073709551615 4194304 5184042 140733315153888 140733315151192 139883382456705 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 21606 14886 842 242 0 14168 0 Current children cumulated CPU time (s) 16.74 Current children cumulated vsize (KiB) 86424 [startup+17.2002 s] /proc/loadavg: 0.99 0.98 0.92 2/56 29262 /proc/meminfo: memFree=256636/1022884 swapFree=0/0 [pid=29242] ppid=29241 vsize=79372 CPUtime=17.14 /proc/29242/stat : 29242 (cupt) R 29241 29242 17872 34816 17872 4202496 18231 7199 0 0 1698 10 5 1 20 0 1 0 28664009 81276928 13258 18446744073709551615 4194304 5184042 140733315153888 140733315153048 139883398939927 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29242/statm: 19843 13258 853 242 0 12405 0 Current children cumulated CPU time (s) 17.14 Current children cumulated vsize (KiB) 79372 Child status: 1 Real time (s): 17.2563 CPU time (s): 17.2171 CPU user time (s): 17.0811 CPU system time (s): 0.136008 CPU usage (%): 99.7726 Max. virtual memory (cumulated for all children) (KiB): 87440 getrusage(RUSAGE_CHILDREN,...) data: user time used= 17.0811 system time used= 0.136008 maximum resident set size= 60976 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 25450 page faults= 0 swaps= 0 block input operations= 0 block output operations= 152 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 271 runsolver used 0.016001 second user time and 0.060003 second system time The end