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/142.runsolver.aptitude aptitude -s -y --without-recommends remove libfontconfig1 hotplug libxml2 gnumeric libssl-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: 1.00 1.01 1.00 2/55 22502 /proc/meminfo: memFree=903728/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=3152 CPUtime=0 /proc/22502/stat : 22502 (runsolver) R 22501 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28697708 3227648 33 18446744073709551615 134512640 134586868 4288501152 4288499200 4151936048 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.125384 s] /proc/loadavg: 1.00 1.01 1.00 2/55 22502 /proc/meminfo: memFree=903728/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=89152 CPUtime=0.11 /proc/22502/stat : 22502 (aptitude) R 22501 22502 17863 34816 17863 4202496 7767 1710 0 0 10 1 0 0 20 0 1 0 28697708 91291648 7567 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569063200 139891163797664 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 22288 7567 6656 1052 0 858 0 Current children cumulated CPU time (s) 0.11 Current children cumulated vsize (KiB) 89152 [startup+0.200357 s] /proc/loadavg: 1.00 1.01 1.00 2/55 22502 /proc/meminfo: memFree=903728/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=89152 CPUtime=0.18 /proc/22502/stat : 22502 (aptitude) R 22501 22502 17863 34816 17863 4202496 7870 1710 0 0 17 1 0 0 20 0 1 0 28697708 91291648 7662 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569061712 139891163809762 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 22288 7662 6726 1052 0 858 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 89152 [startup+0.300275 s] /proc/loadavg: 1.00 1.01 1.00 2/55 22502 /proc/meminfo: memFree=903728/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=101864 CPUtime=0.29 /proc/22502/stat : 22502 (aptitude) R 22501 22502 17863 34816 17863 4202496 11708 1710 0 0 27 2 0 0 20 0 1 0 28697708 104308736 10755 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569061368 139891126496783 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 25466 10755 6745 1052 0 4036 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 101864 [startup+0.700208 s] /proc/loadavg: 1.00 1.01 1.00 2/55 22502 /proc/meminfo: memFree=903728/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=113880 CPUtime=0.68 /proc/22502/stat : 22502 (aptitude) R 22501 22502 17863 34816 17863 4202496 13631 1710 0 0 63 5 0 0 20 0 2 0 28697708 116613120 12003 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569063208 139891171187440 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 28470 12003 6959 1052 0 7040 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 113880 [startup+1.50024 s] /proc/loadavg: 1.00 1.01 1.00 2/57 22507 /proc/meminfo: memFree=883260/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=115260 CPUtime=1.47 /proc/22502/stat : 22502 (aptitude) R 22501 22502 17863 34816 17863 4202496 13841 1710 0 0 142 5 0 0 20 0 2 0 28697708 118026240 12210 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569058640 139891126456624 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 28815 12210 7033 1052 0 7385 0 [pid=22502/tid=22507] ppid=22501 vsize=115260 CPUtime=0 /proc/22502/task/22507/stat : 22507 (aptitude) S 22501 22502 17863 34816 17863 4202560 4 1710 0 0 0 0 0 0 20 0 2 0 28697753 118026240 12210 18446744073709551615 139891168956416 139891173263768 140733569071936 139891072362496 139891137700564 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) 115260 [startup+3.10024 s] /proc/loadavg: 1.00 1.01 1.00 2/57 22507 /proc/meminfo: memFree=865280/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=221224 CPUtime=3.08 /proc/22502/stat : 22502 (aptitude) S 22501 22502 17863 34816 17863 4202496 24228 1710 0 0 300 8 0 0 20 0 2 0 28697708 226533376 22596 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569063696 139891137701451 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 55306 22596 7088 1052 0 33876 0 [pid=22502/tid=22507] ppid=22501 vsize=221224 CPUtime=1.36 /proc/22502/task/22507/stat : 22507 (aptitude) R 22501 22502 17863 34816 17863 4202560 10385 1710 0 0 134 2 0 0 20 0 2 0 28697753 226533376 22596 18446744073709551615 139891168956416 139891173263768 140733569071936 139891072352552 139891171566621 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) 221224 Solver just ended. Dumping a history of the last processes samples [startup+3.20031 s] /proc/loadavg: 1.00 1.01 1.00 2/57 22507 /proc/meminfo: memFree=865280/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=223336 CPUtime=3.18 /proc/22502/stat : 22502 (aptitude) S 22501 22502 17863 34816 17863 4202496 24762 1710 0 0 310 8 0 0 20 0 2 0 28697708 228696064 23130 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569063696 139891137701451 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 55834 23130 7088 1052 0 34404 0 [pid=22502/tid=22507] ppid=22501 vsize=223336 CPUtime=1.46 /proc/22502/task/22507/stat : 22507 (aptitude) R 22501 22502 17863 34816 17863 4202560 10919 1710 0 0 144 2 0 0 20 0 2 0 28697753 228696064 23130 18446744073709551615 139891168956416 139891173263768 140733569071936 139891072352744 139891171602748 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) 223336 [startup+3.6003 s] /proc/loadavg: 1.00 1.01 1.00 2/57 22507 /proc/meminfo: memFree=837504/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=231260 CPUtime=3.57 /proc/22502/stat : 22502 (aptitude) S 22501 22502 17863 34816 17863 4202496 26762 1710 0 0 348 9 0 0 20 0 2 0 28697708 236810240 25130 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569063696 139891137701451 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 57815 25130 7091 1052 0 36385 0 [pid=22502/tid=22507] ppid=22501 vsize=231260 CPUtime=1.85 /proc/22502/task/22507/stat : 22507 (aptitude) R 22501 22502 17863 34816 17863 4202560 12919 1710 0 0 182 3 0 0 20 0 2 0 28697753 236810240 25130 18446744073709551615 139891168956416 139891173263768 140733569071936 139891072355928 139891126456629 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.57 Current children cumulated vsize (KiB) 231260 [startup+4.00024 s] /proc/loadavg: 1.00 1.01 1.00 2/57 22507 /proc/meminfo: memFree=837504/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=233576 CPUtime=3.97 /proc/22502/stat : 22502 (aptitude) R 22501 22502 17863 34816 17863 4202496 27558 1710 0 0 387 10 0 0 20 0 2 0 28697708 239181824 25850 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569064136 139891171162791 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 58394 25850 7140 1052 0 36957 0 [pid=22502/tid=22507] ppid=22501 vsize=233576 CPUtime=2.02 /proc/22502/task/22507/stat : 22507 (aptitude) S 22501 22502 17863 34816 17863 4202560 13467 1710 0 0 198 4 0 0 20 0 2 0 28697753 239181824 25850 18446744073709551615 139891168956416 139891173263768 140733569071936 139891072362496 139891137700564 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.97 Current children cumulated vsize (KiB) 233576 [startup+4.10025 s] /proc/loadavg: 1.00 1.01 1.00 2/57 22507 /proc/meminfo: memFree=837504/1022884 swapFree=0/0 [pid=22502] ppid=22501 vsize=233576 CPUtime=4.07 /proc/22502/stat : 22502 (aptitude) R 22501 22502 17863 34816 17863 4202496 27614 1710 0 0 397 10 0 0 20 0 2 0 28697708 239181824 25858 18446744073709551615 139891168956416 139891173263768 140733569071936 140733569064040 139891126447678 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22502/statm: 58394 25858 7148 1052 0 36957 0 [pid=22502/tid=22507] ppid=22501 vsize=233576 CPUtime=2.02 /proc/22502/task/22507/stat : 22507 (aptitude) S 22501 22502 17863 34816 17863 4202560 13467 1710 0 0 198 4 0 0 20 0 2 0 28697753 239181824 25858 18446744073709551615 139891168956416 139891173263768 140733569071936 139891072362496 139891137700564 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.07 Current children cumulated vsize (KiB) 233576 Child status: 0 Real time (s): 4.15499 CPU time (s): 4.14026 CPU user time (s): 4.00825 CPU system time (s): 0.132008 CPU usage (%): 99.6455 Max. virtual memory (cumulated for all children) (KiB): 233576 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.00825 system time used= 0.132008 maximum resident set size= 103600 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 29391 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= 60 involuntary context switches= 121 runsolver used 0.004 second user time and 0.020001 second system time The end