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/logs/124.runsolver.aptitude aptitude -s -y --without-recommends remove tk8.4-dev khangman tidy libart-2.0-2 python 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.11 1.09 1.04 2/55 24440 /proc/meminfo: memFree=865636/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=54860 CPUtime=0 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 587 0 0 0 0 0 0 0 20 0 1 0 29226786 56176640 486 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568281304 139720748603333 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 13715 486 398 1052 0 73 0 [startup+0.123331 s] /proc/loadavg: 1.11 1.09 1.04 2/55 24440 /proc/meminfo: memFree=865636/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=100508 CPUtime=0.1 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 10553 1710 0 0 8 2 0 0 20 0 1 0 29226786 102920192 10354 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568273360 139720745645521 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 25127 10354 9179 1052 0 1122 0 Current children cumulated CPU time (s) 0.1 Current children cumulated vsize (KiB) 100508 [startup+0.200283 s] /proc/loadavg: 1.11 1.09 1.04 2/55 24440 /proc/meminfo: memFree=865636/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=100508 CPUtime=0.18 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 10606 1710 0 0 16 2 0 0 20 0 1 0 29226786 102920192 10407 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568273360 139720708953280 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 100508 [startup+0.300285 s] /proc/loadavg: 1.11 1.09 1.04 2/55 24440 /proc/meminfo: memFree=865636/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=111108 CPUtime=0.29 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 12842 1710 0 0 26 3 0 0 20 0 1 0 29226786 113774592 12635 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568273688 139720709018210 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 27777 12635 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.700268 s] /proc/loadavg: 1.11 1.09 1.04 2/55 24440 /proc/meminfo: memFree=865636/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=123288 CPUtime=0.68 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 17025 1710 0 0 62 6 0 0 20 0 2 0 29226786 126246912 14299 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568275720 139720745655207 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 30822 14299 9478 1052 0 6817 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123288 [startup+1.50024 s] /proc/loadavg: 1.10 1.09 1.04 2/57 24445 /proc/meminfo: memFree=837728/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=131976 CPUtime=1.48 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 19305 1710 0 0 142 6 0 0 20 0 2 0 29226786 135143424 16575 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568270216 139720745628656 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 32994 16575 9567 1052 0 8989 0 [pid=24440/tid=24445] ppid=24439 vsize=131976 CPUtime=0 /proc/24440/task/24445/stat : 24445 (aptitude) S 24439 24440 17863 34816 17863 4202560 4 1710 0 0 0 0 0 0 20 0 2 0 29226851 135143424 16575 18446744073709551615 139720750800896 139720755108248 140736568282096 139720641628160 139720719545044 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) 131976 [startup+3.10028 s] /proc/loadavg: 1.10 1.09 1.04 2/57 24445 /proc/meminfo: memFree=836984/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=155380 CPUtime=3.07 /proc/24440/stat : 24440 (aptitude) S 24439 24440 17863 34816 17863 4202496 25240 1710 0 0 299 8 0 0 20 0 2 0 29226786 159109120 22508 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568273856 139720719545931 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 38845 22508 9658 1052 0 14840 0 [pid=24440/tid=24445] ppid=24439 vsize=155380 CPUtime=0.54 /proc/24440/task/24445/stat : 24445 (aptitude) R 24439 24440 17863 34816 17863 4202560 5791 1710 0 0 52 2 0 0 20 0 2 0 29226851 159109120 22508 18446744073709551615 139720750800896 139720755108248 140736568282096 139720641618888 139720754224528 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) 155380 [startup+6.30028 s] /proc/loadavg: 1.10 1.09 1.04 2/57 24445 /proc/meminfo: memFree=754400/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=217124 CPUtime=6.26 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 40756 1710 0 0 613 13 0 0 20 0 2 0 29226786 222334976 38022 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568269960 139720745648909 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 54281 38022 9711 1052 0 30269 0 [pid=24440/tid=24445] ppid=24439 vsize=217124 CPUtime=3.4 /proc/24440/task/24445/stat : 24445 (aptitude) S 24439 24440 17863 34816 17863 4202560 21121 1710 0 0 334 6 0 0 20 0 2 0 29226851 222334976 38022 18446744073709551615 139720750800896 139720755108248 140736568282096 139720641628160 139720719545044 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.26 Current children cumulated vsize (KiB) 217124 Solver just ended. Dumping a history of the last processes samples [startup+6.40032 s] /proc/loadavg: 1.10 1.09 1.04 2/57 24445 /proc/meminfo: memFree=754400/1022884 swapFree=0/0 [pid=24440] ppid=24439 vsize=217124 CPUtime=6.36 /proc/24440/stat : 24440 (aptitude) R 24439 24440 17863 34816 17863 4202496 40756 1710 0 0 623 13 0 0 20 0 2 0 29226786 222334976 38022 18446744073709551615 139720750800896 139720755108248 140736568282096 140736568269960 139720753008388 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24440/statm: 54281 38022 9711 1052 0 30269 0 [pid=24440/tid=24445] ppid=24439 vsize=217124 CPUtime=3.4 /proc/24440/task/24445/stat : 24445 (aptitude) S 24439 24440 17863 34816 17863 4202560 21121 1710 0 0 334 6 0 0 20 0 2 0 29226851 222334976 38022 18446744073709551615 139720750800896 139720755108248 140736568282096 139720641628160 139720719545044 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.36 Current children cumulated vsize (KiB) 217124 Child status: 0 Real time (s): 6.48271 CPU time (s): 6.4564 CPU user time (s): 6.28039 CPU system time (s): 0.176011 CPU usage (%): 99.5941 Max. virtual memory (cumulated for all children) (KiB): 217124 getrusage(RUSAGE_CHILDREN,...) data: user time used= 6.28039 system time used= 0.176011 maximum resident set size= 152132 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 42542 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= 62 involuntary context switches= 156 runsolver used 0.008 second user time and 0.024001 second system time The end