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/30.runsolver.aptitude aptitude -s -y --without-recommends install openslp-doc honeyd-common planetpenguin-racer abcmidi-yaps forutil 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.09 1.08 1.04 2/55 25248 /proc/meminfo: memFree=948492/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=3152 CPUtime=0 /proc/25248/stat : 25248 (runsolver) D 25247 25248 17863 34816 17863 4202560 80 0 0 0 0 0 0 0 20 0 1 0 29448352 3227648 102 18446744073709551615 134512640 134586868 4290945904 4290943872 4151497776 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/25248/statm: 788 102 69 19 0 73 0 [startup+0.200819 s] /proc/loadavg: 1.09 1.08 1.04 2/55 25248 /proc/meminfo: memFree=948492/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=30864 CPUtime=0 /proc/25248/stat : 25248 (aptitude) D 25247 25248 17863 34816 17863 4202496 161 0 11 0 0 0 0 0 20 0 1 0 29448352 31604736 82 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434809160 140337800749846 0 0 0 0 0 0 0 17 0 0 0 18 0 0 /proc/25248/statm: 7716 82 52 1052 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 30864 [startup+0.300373 s] /proc/loadavg: 1.09 1.08 1.04 2/55 25248 /proc/meminfo: memFree=948492/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=54968 CPUtime=0.01 /proc/25248/stat : 25248 (aptitude) D 25247 25248 17863 34816 17863 4202496 1023 0 24 0 0 1 0 0 20 0 1 0 29448352 56287232 937 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434807656 140337760736512 0 134217728 4096 0 0 0 0 17 0 0 0 28 0 0 /proc/25248/statm: 13742 937 783 1052 0 106 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 54968 [startup+0.400402 s] /proc/loadavg: 1.09 1.08 1.04 2/55 25248 /proc/meminfo: memFree=948492/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=61308 CPUtime=0.01 /proc/25248/stat : 25248 (aptitude) D 25247 25248 17863 34816 17863 4202496 1142 0 26 0 0 1 0 0 20 0 1 0 29448352 62779392 1050 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434805336 140337800750627 0 134217728 4096 0 0 0 0 17 0 0 0 37 0 0 /proc/25248/statm: 15327 1050 875 1052 0 108 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 61308 [startup+0.700324 s] /proc/loadavg: 1.09 1.08 1.04 2/55 25248 /proc/meminfo: memFree=948492/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=103288 CPUtime=0.1 /proc/25248/stat : 25248 (aptitude) D 25247 25248 17863 34816 17863 4202496 11016 1707 55 2 8 2 0 0 20 0 1 0 29448352 105766912 10872 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434803808 140337797736337 0 134217728 4096 0 0 0 0 17 0 0 0 56 0 0 /proc/25248/statm: 25822 10872 9660 1052 0 1159 0 Current children cumulated CPU time (s) 0.1 Current children cumulated vsize (KiB) 103288 [startup+1.50021 s] /proc/loadavg: 1.09 1.08 1.04 1/56 25252 /proc/meminfo: memFree=914508/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=123068 CPUtime=0.6 /proc/25248/stat : 25248 (aptitude) R 25247 25248 17863 34816 17863 4202496 17623 1707 59 2 51 9 0 0 20 0 1 0 29448352 126021632 15959 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434801976 140337760431647 0 134217728 4096 0 0 0 0 17 0 0 0 87 0 0 /proc/25248/statm: 30767 15959 9976 1052 0 6104 0 Current children cumulated CPU time (s) 0.6 Current children cumulated vsize (KiB) 123068 [startup+3.1002 s] /proc/loadavg: 1.09 1.08 1.04 1/56 25252 /proc/meminfo: memFree=815680/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=136044 CPUtime=1.56 /proc/25248/stat : 25248 (aptitude) R 25247 25248 17863 34816 17863 4202496 20581 1707 59 2 142 14 0 0 20 0 2 0 29448352 139309056 17558 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434803816 140337797715348 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 151 0 0 /proc/25248/statm: 34011 17558 10207 1052 0 9348 0 Current children cumulated CPU time (s) 1.56 Current children cumulated vsize (KiB) 136044 heavy processes: [startup+6.30024 s] /proc/loadavg: 1.09 1.08 1.04 2/57 25254 /proc/meminfo: memFree=790624/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=228940 CPUtime=4.72 /proc/25248/stat : 25248 (aptitude) S 25247 25248 17863 34816 17863 4202496 28802 2204 59 3 450 21 0 1 20 0 2 0 29448352 234434560 24560 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434804304 140337771636299 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 153 0 0 /proc/25248/statm: 57235 24560 10359 1052 0 32572 0 [pid=25248/tid=25253] ppid=25247 vsize=228940 CPUtime=1.28 /proc/25248/task/25253/stat : 25253 (aptitude) R 25247 25248 17863 34816 17863 4202560 6877 2204 0 3 124 3 0 1 20 0 2 0 29448588 234434560 24560 18446744073709551615 140337802891264 140337807198616 140735434812544 140337690562360 140337805599287 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.72 Current children cumulated vsize (KiB) 228940 heavy processes: [startup+12.7002 s] /proc/loadavg: 1.07 1.08 1.04 2/57 25254 /proc/meminfo: memFree=725152/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=285028 CPUtime=11.08 /proc/25248/stat : 25248 (aptitude) S 25247 25248 17863 34816 17863 4202496 43296 2204 59 3 1080 27 0 1 20 0 2 0 29448352 291868672 38604 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434804304 140337771636299 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 153 0 0 /proc/25248/statm: 71257 38604 10359 1052 0 46594 0 [pid=25248/tid=25253] ppid=25247 vsize=285028 CPUtime=7.64 /proc/25248/task/25253/stat : 25253 (aptitude) R 25247 25248 17863 34816 17863 4202560 21371 2204 0 3 754 9 0 1 20 0 2 0 29448588 291868672 38604 18446744073709551615 140337802891264 140337807198616 140735434812544 140337690560024 140337806316392 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.08 Current children cumulated vsize (KiB) 285028 [startup+25.5033 s] /proc/loadavg: 1.06 1.08 1.03 2/57 25254 /proc/meminfo: memFree=649636/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=355712 CPUtime=23.74 /proc/25248/stat : 25248 (aptitude) R 25247 25248 17863 34816 17863 4202496 64209 2702 72 3 2331 41 0 2 20 0 2 0 29448352 364249088 56505 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434802632 140337760735301 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 160 0 0 /proc/25248/statm: 88928 56505 10409 1052 0 64258 0 [pid=25248/tid=25253] ppid=25247 vsize=355712 CPUtime=19.5 /proc/25248/task/25253/stat : 25253 (aptitude) S 25247 25248 17863 34816 17863 4202560 39289 2702 1 3 1931 17 0 2 20 0 2 0 29448588 364249088 56505 18446744073709551615 140337802891264 140337807198616 140735434812544 140337690568704 140337771635412 0 134217728 4096 0 0 0 0 -1 0 0 0 1 0 0 Current children cumulated CPU time (s) 23.74 Current children cumulated vsize (KiB) 355712 Solver just ended. Dumping a history of the last processes samples [startup+25.7004 s] /proc/loadavg: 1.06 1.08 1.03 2/57 25254 /proc/meminfo: memFree=649636/1022884 swapFree=0/0 [pid=25248] ppid=25247 vsize=183824 CPUtime=23.91 /proc/25248/stat : 25248 (aptitude) D 25247 25248 17863 34816 17863 4202496 64797 2702 77 3 2339 50 0 2 20 0 1 0 29448352 188235776 13690 18446744073709551615 140337802891264 140337807198616 140735434812544 140735434809856 140337803616624 0 134217728 4096 0 0 0 0 17 0 0 0 162 0 0 /proc/25248/statm: 45956 13690 1507 1052 0 30212 0 Current children cumulated CPU time (s) 23.91 Current children cumulated vsize (KiB) 183824 Child status: 0 Real time (s): 25.755 CPU time (s): 23.9335 CPU user time (s): 23.3975 CPU system time (s): 0.536033 CPU usage (%): 92.9275 Max. virtual memory (cumulated for all children) (KiB): 355712 getrusage(RUSAGE_CHILDREN,...) data: user time used= 23.3975 system time used= 0.536033 maximum resident set size= 226472 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 67558 page faults= 92 swaps= 0 block input operations= 229920 block output operations= 144 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 2149 involuntary context switches= 469 runsolver used 0.048003 second user time and 0.080005 second system time The end