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/105.runsolver.aptitude aptitude -s -y --without-recommends remove libbonoboui2-common libtext-wrapi18n-perl gnome-desktop-data gsfonts libtextwrap1 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.04 1.07 1.08 2/55 26614 /proc/meminfo: memFree=832856/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=3152 CPUtime=0 /proc/26614/stat : 26614 (runsolver) R 26613 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29891301 3227648 33 18446744073709551615 134512640 134586868 4294242400 4294240448 4152022064 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.163379 s] /proc/loadavg: 1.04 1.07 1.08 2/55 26614 /proc/meminfo: memFree=832856/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=103288 CPUtime=0.15 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 11288 1706 0 0 12 3 0 0 20 0 1 0 29891301 105766912 11089 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680846736 139859387457721 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 25822 11089 9878 1052 0 1159 0 Current children cumulated CPU time (s) 0.15 Current children cumulated vsize (KiB) 103288 [startup+0.200287 s] /proc/loadavg: 1.04 1.07 1.08 2/55 26614 /proc/meminfo: memFree=832856/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=103288 CPUtime=0.18 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 11299 1706 0 0 15 3 0 0 20 0 1 0 29891301 105766912 11100 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680846736 139859387459549 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 25822 11100 9889 1052 0 1159 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 103288 [startup+0.300274 s] /proc/loadavg: 1.04 1.07 1.08 2/55 26614 /proc/meminfo: memFree=832856/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=103432 CPUtime=0.28 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 11426 1706 0 0 25 3 0 0 20 0 1 0 29891301 105914368 11219 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680845248 139859387431028 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 25858 11219 9956 1052 0 1195 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 103432 [startup+0.700205 s] /proc/loadavg: 1.04 1.07 1.08 2/55 26614 /proc/meminfo: memFree=832856/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=123068 CPUtime=0.68 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 17687 1706 0 0 61 7 0 0 20 0 1 0 29891301 126021632 15964 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680844904 139859350154759 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 30767 15964 9976 1052 0 6104 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123068 [startup+1.50024 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=803708/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=135852 CPUtime=1.47 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 20624 1706 0 0 139 8 0 0 20 0 2 0 29891301 139112448 17542 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680842344 139859350124680 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 33963 17542 10226 1052 0 9300 0 [pid=26614/tid=26619] ppid=26613 vsize=135852 CPUtime=0 /proc/26614/task/26619/stat : 26619 (aptitude) S 26613 26614 17863 34816 17863 4202560 4 1706 0 0 0 0 0 0 20 0 2 0 29891378 139112448 17542 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280291840 139859361358548 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.47 Current children cumulated vsize (KiB) 135852 [startup+3.10024 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=802840/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=160144 CPUtime=3.07 /proc/26614/stat : 26614 (aptitude) S 26613 26614 17863 34816 17863 4202496 26795 1706 0 0 297 10 0 0 20 0 2 0 29891301 163987456 23712 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680847232 139859361359435 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 40036 23712 10317 1052 0 15373 0 [pid=26614/tid=26619] ppid=26613 vsize=160144 CPUtime=0.28 /proc/26614/task/26619/stat : 26619 (aptitude) R 26613 26614 17863 34816 17863 4202560 6013 1706 0 0 26 2 0 0 20 0 2 0 29891378 163987456 23712 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280282776 139859358635432 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) 160144 [startup+6.30024 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=708848/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=247948 CPUtime=6.25 /proc/26614/stat : 26614 (aptitude) S 26613 26614 17863 34816 17863 4202496 48731 1706 0 0 608 17 0 0 20 0 2 0 29891301 253898752 45648 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680847232 139859361359435 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 61987 45648 10319 1052 0 37324 0 [pid=26614/tid=26619] ppid=26613 vsize=247948 CPUtime=3.45 /proc/26614/task/26619/stat : 26619 (aptitude) R 26613 26614 17863 34816 17863 4202560 27948 1706 0 0 337 8 0 0 20 0 2 0 29891378 253898752 45648 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280282728 139859388014536 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.25 Current children cumulated vsize (KiB) 247948 Solver just ended. Dumping a history of the last processes samples [startup+6.40032 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=708848/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=248744 CPUtime=6.35 /proc/26614/stat : 26614 (aptitude) S 26613 26614 17863 34816 17863 4202496 48937 1706 0 0 618 17 0 0 20 0 2 0 29891301 254713856 45854 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680847232 139859361359435 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 62186 45854 10319 1052 0 37523 0 [pid=26614/tid=26619] ppid=26613 vsize=248744 CPUtime=3.55 /proc/26614/task/26619/stat : 26619 (aptitude) R 26613 26614 17863 34816 17863 4202560 28154 1706 0 0 347 8 0 0 20 0 2 0 29891378 254713856 45854 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280285496 139859394825309 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.35 Current children cumulated vsize (KiB) 248744 [startup+7.20024 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=687024/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=262220 CPUtime=7.16 /proc/26614/stat : 26614 (aptitude) S 26613 26614 17863 34816 17863 4202496 52305 1706 0 0 698 18 0 0 20 0 2 0 29891301 268513280 49222 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680847232 139859361359435 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 65555 49222 10321 1052 0 40892 0 [pid=26614/tid=26619] ppid=26613 vsize=262220 CPUtime=4.35 /proc/26614/task/26619/stat : 26619 (aptitude) R 26613 26614 17863 34816 17863 4202560 31522 1706 0 0 426 9 0 0 20 0 2 0 29891378 268513280 49222 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280281848 139859388015315 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 7.16 Current children cumulated vsize (KiB) 262220 [startup+8.00025 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=671400/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=267516 CPUtime=7.94 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 53698 1706 0 0 776 18 0 0 20 0 2 0 29891301 273936384 50613 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680845560 139859350105543 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 66879 50613 10370 1052 0 42209 0 [pid=26614/tid=26619] ppid=26613 vsize=267516 CPUtime=4.84 /proc/26614/task/26619/stat : 26619 (aptitude) S 26613 26614 17863 34816 17863 4202560 32600 1706 0 0 474 10 0 0 20 0 2 0 29891378 273936384 50613 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280291840 139859361358548 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 7.94 Current children cumulated vsize (KiB) 267516 [startup+8.40024 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=671400/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=267516 CPUtime=8.34 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 53698 1706 0 0 816 18 0 0 20 0 2 0 29891301 273936384 50613 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680843336 139859394820895 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 66879 50613 10370 1052 0 42209 0 [pid=26614/tid=26619] ppid=26613 vsize=267516 CPUtime=4.84 /proc/26614/task/26619/stat : 26619 (aptitude) S 26613 26614 17863 34816 17863 4202560 32600 1706 0 0 474 10 0 0 20 0 2 0 29891378 273936384 50613 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280291840 139859361358548 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 8.34 Current children cumulated vsize (KiB) 267516 [startup+8.50025 s] /proc/loadavg: 1.03 1.07 1.08 2/57 26619 /proc/meminfo: memFree=671400/1022884 swapFree=0/0 [pid=26614] ppid=26613 vsize=267516 CPUtime=8.44 /proc/26614/stat : 26614 (aptitude) R 26613 26614 17863 34816 17863 4202496 53707 1706 0 0 826 18 0 0 20 0 2 0 29891301 273936384 50621 18446744073709551615 139859392614400 139859396921752 140736680855472 140736680838872 139859394347898 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26614/statm: 66879 50621 10378 1052 0 42209 0 [pid=26614/tid=26619] ppid=26613 vsize=267516 CPUtime=4.84 /proc/26614/task/26619/stat : 26619 (aptitude) S 26613 26614 17863 34816 17863 4202560 32600 1706 0 0 474 10 0 0 20 0 2 0 29891378 273936384 50621 18446744073709551615 139859392614400 139859396921752 140736680855472 139859280291840 139859361358548 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 8.44 Current children cumulated vsize (KiB) 267516 Child status: 0 Real time (s): 8.555 CPU time (s): 8.52053 CPU user time (s): 8.28052 CPU system time (s): 0.240015 CPU usage (%): 99.5971 Max. virtual memory (cumulated for all children) (KiB): 267516 getrusage(RUSAGE_CHILDREN,...) data: user time used= 8.28052 system time used= 0.240015 maximum resident set size= 202496 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 55481 page faults= 0 swaps= 0 block input operations= 0 block output operations= 80 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 65 involuntary context switches= 189 runsolver used 0.020001 second user time and 0.024001 second system time The end