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-squeeze-sid/logs/155.runsolver.aptitude aptitude -s -y --without-recommends remove libmlgtk-ocaml-dev kompare kdebase-kio-plugins kdeadmin liblzo1 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.21 1.08 1.06 2/55 26967 /proc/meminfo: memFree=834708/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=54860 CPUtime=0 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 625 0 0 0 0 0 0 0 20 0 1 0 29950934 56176640 525 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094930056 140346789432062 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 13715 525 431 1052 0 73 0 [startup+0.137212 s] /proc/loadavg: 1.21 1.08 1.06 2/55 26967 /proc/meminfo: memFree=834708/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=103288 CPUtime=0.12 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 11274 1708 0 0 10 2 0 0 20 0 1 0 29950934 105766912 11075 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094922112 140346786465392 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 25822 11075 9864 1052 0 1159 0 Current children cumulated CPU time (s) 0.12 Current children cumulated vsize (KiB) 103288 [startup+0.200267 s] /proc/loadavg: 1.21 1.08 1.06 2/55 26967 /proc/meminfo: memFree=834708/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=103288 CPUtime=0.18 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 11301 1708 0 0 16 2 0 0 20 0 1 0 29950934 105766912 11102 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094922112 140346749210333 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 25822 11102 9891 1052 0 1159 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 103288 [startup+0.300253 s] /proc/loadavg: 1.21 1.08 1.06 2/55 26967 /proc/meminfo: memFree=834708/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=114256 CPUtime=0.29 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 14137 1708 0 0 26 3 0 0 20 0 1 0 29950934 116998144 13930 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094922496 140346748859456 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 28564 13930 9961 1052 0 3901 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 114256 [startup+0.700203 s] /proc/loadavg: 1.21 1.08 1.06 2/55 26967 /proc/meminfo: memFree=834708/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=123068 CPUtime=0.68 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 17687 1708 0 0 62 6 0 0 20 0 1 0 29950934 126021632 15964 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094920280 140346760384880 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 30767 15964 9976 1052 0 6104 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123068 [startup+1.50025 s] /proc/loadavg: 1.19 1.08 1.06 2/57 26972 /proc/meminfo: memFree=805684/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=135852 CPUtime=1.48 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 20630 1708 0 0 141 7 0 0 20 0 2 0 29950934 139112448 17548 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094917960 140346749139080 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 33963 17548 10227 1052 0 9300 0 [pid=26967/tid=26972] ppid=26966 vsize=135852 CPUtime=0 /proc/26967/task/26972/stat : 26972 (aptitude) S 26966 26967 17863 34816 17863 4202560 4 1708 0 0 0 0 0 0 20 0 2 0 29951006 139112448 17548 18446744073709551615 140346791628800 140346795936152 140736094930848 140346679306240 140346760372948 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) 135852 [startup+3.10026 s] /proc/loadavg: 1.19 1.08 1.06 2/57 26972 /proc/meminfo: memFree=804692/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=153016 CPUtime=3.08 /proc/26967/stat : 26967 (aptitude) S 26966 26967 17863 34816 17863 4202496 25001 1708 0 0 300 8 0 0 20 0 2 0 29950934 156688384 21918 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094922608 140346760373835 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 38254 21918 10316 1052 0 13591 0 [pid=26967/tid=26972] ppid=26966 vsize=153016 CPUtime=0.3 /proc/26967/task/26972/stat : 26972 (aptitude) R 26966 26967 17863 34816 17863 4202560 4218 1708 0 0 30 0 0 0 20 0 2 0 29951006 156688384 21918 18446744073709551615 140346791628800 140346795936152 140736094930848 140346679299672 140346794261010 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 153016 Solver just ended. Dumping a history of the last processes samples [startup+3.20032 s] /proc/loadavg: 1.19 1.08 1.06 2/57 26972 /proc/meminfo: memFree=804692/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=157108 CPUtime=3.18 /proc/26967/stat : 26967 (aptitude) S 26966 26967 17863 34816 17863 4202496 26044 1708 0 0 310 8 0 0 20 0 2 0 29950934 160878592 22961 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094922608 140346760373835 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 39277 22961 10316 1052 0 14614 0 [pid=26967/tid=26972] ppid=26966 vsize=157108 CPUtime=0.4 /proc/26967/task/26972/stat : 26972 (aptitude) R 26966 26967 17863 34816 17863 4202560 5261 1708 0 0 40 0 0 0 20 0 2 0 29951006 160878592 22961 18446744073709551615 140346791628800 140346795936152 140736094930848 140346679297128 140346749132340 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.18 Current children cumulated vsize (KiB) 157108 [startup+4.80025 s] /proc/loadavg: 1.19 1.08 1.06 2/57 26972 /proc/meminfo: memFree=731284/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=285796 CPUtime=4.76 /proc/26967/stat : 26967 (aptitude) S 26966 26967 17863 34816 17863 4202496 41816 1708 0 0 466 10 0 0 20 0 2 0 29950934 292655104 38733 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094922608 140346760373835 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 71449 38733 10321 1052 0 46786 0 [pid=26967/tid=26972] ppid=26966 vsize=285796 CPUtime=2 /proc/26967/task/26972/stat : 26972 (aptitude) R 26966 26967 17863 34816 17863 4202560 21031 1708 0 0 197 3 0 0 20 0 2 0 29951006 292655104 38733 18446744073709551615 140346791628800 140346795936152 140736094930848 140346679294568 140346787028936 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.76 Current children cumulated vsize (KiB) 285796 [startup+5.60322 s] /proc/loadavg: 1.18 1.08 1.06 2/57 26972 /proc/meminfo: memFree=712932/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=292976 CPUtime=5.56 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 43825 1708 0 0 546 10 0 0 20 0 2 0 29950934 300007424 40689 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094923048 140346792457835 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 73244 40689 10370 1052 0 48574 0 [pid=26967/tid=26972] ppid=26966 vsize=292976 CPUtime=2.51 /proc/26967/task/26972/stat : 26972 (aptitude) S 26966 26967 17863 34816 17863 4202560 22836 1708 0 0 248 3 0 0 20 0 2 0 29951006 300007424 40689 18446744073709551615 140346791628800 140346795936152 140736094930848 140346679306240 140346760372948 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 5.56 Current children cumulated vsize (KiB) 292976 [startup+5.80025 s] /proc/loadavg: 1.18 1.08 1.06 2/57 26972 /proc/meminfo: memFree=712932/1022884 swapFree=0/0 [pid=26967] ppid=26966 vsize=292976 CPUtime=5.75 /proc/26967/stat : 26967 (aptitude) R 26966 26967 17863 34816 17863 4202496 43933 1708 0 0 565 10 0 0 20 0 2 0 29950934 300007424 40666 18446744073709551615 140346791628800 140346795936152 140736094930848 140736094922952 140346749119943 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26967/statm: 73244 40666 10378 1052 0 48574 0 [pid=26967/tid=26972] ppid=26966 vsize=292976 CPUtime=2.51 /proc/26967/task/26972/stat : 26972 (aptitude) S 26966 26967 17863 34816 17863 4202560 22836 1708 0 0 248 3 0 0 20 0 2 0 29951006 300007424 40666 18446744073709551615 140346791628800 140346795936152 140736094930848 140346679306240 140346760372948 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 5.75 Current children cumulated vsize (KiB) 292976 Child status: 0 Real time (s): 5.8724 CPU time (s): 5.84836 CPU user time (s): 5.69235 CPU system time (s): 0.156009 CPU usage (%): 99.5906 Max. virtual memory (cumulated for all children) (KiB): 292976 getrusage(RUSAGE_CHILDREN,...) data: user time used= 5.69236 system time used= 0.156009 maximum resident set size= 163040 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 45709 page faults= 0 swaps= 0 block input operations= 0 block output operations= 48 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 62 involuntary context switches= 146 runsolver used 0.020001 second user time and 0.012 second system time The end