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/136.runsolver.aptitude aptitude -s -y --without-recommends remove gtkhtml3.2 slang1 secpolicy libnews-nntpclient-perl python2.3-numeric 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.03 2/55 24524 /proc/meminfo: memFree=864768/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=3152 CPUtime=0 /proc/24524/stat : 24524 (runsolver) R 24523 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29232871 3227648 32 18446744073709551615 134512640 134586868 4292631168 4292629216 4152005680 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.183778 s] /proc/loadavg: 1.04 1.07 1.03 2/55 24524 /proc/meminfo: memFree=864768/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=100508 CPUtime=0.17 /proc/24524/stat : 24524 (aptitude) R 24523 24524 17863 34816 17863 4202496 10603 1709 0 0 15 2 0 0 20 0 1 0 29232871 102920192 10404 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663066656 140440826259950 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 25127 10404 9229 1052 0 1122 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 100508 [startup+0.200286 s] /proc/loadavg: 1.04 1.07 1.03 2/55 24524 /proc/meminfo: memFree=864768/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=100508 CPUtime=0.18 /proc/24524/stat : 24524 (aptitude) R 24523 24524 17863 34816 17863 4202496 10606 1709 0 0 16 2 0 0 20 0 1 0 29232871 102920192 10407 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663066656 140440788999885 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 100508 [startup+0.300279 s] /proc/loadavg: 1.04 1.07 1.03 2/55 24524 /proc/meminfo: memFree=864768/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=111108 CPUtime=0.28 /proc/24524/stat : 24524 (aptitude) R 24523 24524 17863 34816 17863 4202496 13124 1709 0 0 26 2 0 0 20 0 1 0 29232871 113774592 12917 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663066984 140440789635852 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 27777 12917 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 111108 [startup+0.70022 s] /proc/loadavg: 1.04 1.07 1.03 2/55 24524 /proc/meminfo: memFree=864768/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=123288 CPUtime=0.68 /proc/24524/stat : 24524 (aptitude) R 24523 24524 17863 34816 17863 4202496 17025 1709 0 0 63 5 0 0 20 0 2 0 29232871 126246912 14299 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663069016 140440833549447 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 30822 14299 9478 1052 0 6817 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123288 [startup+1.50025 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24529 /proc/meminfo: memFree=836736/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=131940 CPUtime=1.47 /proc/24524/stat : 24524 (aptitude) R 24523 24524 17863 34816 17863 4202496 19302 1709 0 0 142 5 0 0 20 0 2 0 29232871 135106560 16572 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663062504 140440833994533 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 32985 16572 9569 1052 0 8980 0 [pid=24524/tid=24529] ppid=24523 vsize=131940 CPUtime=0 /proc/24524/task/24529/stat : 24529 (aptitude) S 24523 24524 17863 34816 17863 4202560 4 1709 0 0 0 0 0 0 20 0 2 0 29232936 135106560 16572 18446744073709551615 140440831418368 140440835725720 140735663075392 140440722245632 140440800162516 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) 131940 [startup+3.10026 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24529 /proc/meminfo: memFree=836116/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=143860 CPUtime=3.07 /proc/24524/stat : 24524 (aptitude) S 24523 24524 17863 34816 17863 4202496 22365 1709 0 0 300 7 0 0 20 0 2 0 29232871 147312640 19634 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663067152 140440800163403 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 35965 19634 9661 1052 0 11960 0 [pid=24524/tid=24529] ppid=24523 vsize=143860 CPUtime=0.55 /proc/24524/task/24529/stat : 24529 (aptitude) R 24523 24524 17863 34816 17863 4202560 2926 1709 0 0 54 1 0 0 20 0 2 0 29232936 147312640 19634 18446744073709551615 140440831418368 140440835725720 140735663075392 140440722237320 140440826103776 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) 143860 Solver just ended. Dumping a history of the last processes samples [startup+3.20034 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24529 /proc/meminfo: memFree=836116/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=145972 CPUtime=3.17 /proc/24524/stat : 24524 (aptitude) S 24523 24524 17863 34816 17863 4202496 22904 1709 0 0 310 7 0 0 20 0 2 0 29232871 149475328 20173 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663067152 140440800163403 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 36493 20173 9661 1052 0 12488 0 [pid=24524/tid=24529] ppid=24523 vsize=145972 CPUtime=0.66 /proc/24524/task/24529/stat : 24529 (aptitude) R 24523 24524 17863 34816 17863 4202560 3465 1709 0 0 64 2 0 0 20 0 2 0 29232936 149475328 20173 18446744073709551615 140440831418368 140440835725720 140735663075392 140440722236520 140440797723613 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.17 Current children cumulated vsize (KiB) 145972 [startup+3.60025 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24529 /proc/meminfo: memFree=820864/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=150856 CPUtime=3.57 /proc/24524/stat : 24524 (aptitude) S 24523 24524 17863 34816 17863 4202496 24136 1709 0 0 349 8 0 0 20 0 2 0 29232871 154476544 21405 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663067152 140440800163403 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 37714 21405 9661 1052 0 13709 0 [pid=24524/tid=24529] ppid=24523 vsize=150856 CPUtime=1.05 /proc/24524/task/24529/stat : 24529 (aptitude) R 24523 24524 17863 34816 17863 4202560 4697 1709 0 0 103 2 0 0 20 0 2 0 29232936 154476544 21405 18446744073709551615 140440831418368 140440835725720 140735663075392 140440722239064 140440826819438 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) 150856 [startup+4.00025 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24529 /proc/meminfo: memFree=820864/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=152864 CPUtime=3.97 /proc/24524/stat : 24524 (aptitude) R 24523 24524 17863 34816 17863 4202496 24684 1709 0 0 389 8 0 0 20 0 2 0 29232871 156532736 21951 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663063256 140440832247344 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 38216 21951 9711 1052 0 14204 0 [pid=24524/tid=24529] ppid=24523 vsize=152864 CPUtime=1.34 /proc/24524/task/24529/stat : 24529 (aptitude) S 24523 24524 17863 34816 17863 4202560 5191 1709 0 0 132 2 0 0 20 0 2 0 29232936 156532736 21951 18446744073709551615 140440831418368 140440835725720 140735663075392 140440722245632 140440800162516 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) 152864 [startup+4.10025 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24529 /proc/meminfo: memFree=820864/1022884 swapFree=0/0 [pid=24524] ppid=24523 vsize=152864 CPUtime=4.07 /proc/24524/stat : 24524 (aptitude) R 24523 24524 17863 34816 17863 4202496 24684 1709 0 0 399 8 0 0 20 0 2 0 29232871 156532736 21951 18446744073709551615 140440831418368 140440835725720 140735663075392 140735663063256 140440833619739 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24524/statm: 38216 21951 9711 1052 0 14204 0 [pid=24524/tid=24529] ppid=24523 vsize=152864 CPUtime=1.34 /proc/24524/task/24529/stat : 24529 (aptitude) S 24523 24524 17863 34816 17863 4202560 5191 1709 0 0 132 2 0 0 20 0 2 0 29232936 156532736 21951 18446744073709551615 140440831418368 140440835725720 140735663075392 140440722245632 140440800162516 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) 152864 Child status: 0 Real time (s): 4.141 CPU time (s): 4.12826 CPU user time (s): 4.02025 CPU system time (s): 0.108006 CPU usage (%): 99.6923 Max. virtual memory (cumulated for all children) (KiB): 152864 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.02025 system time used= 0.108006 maximum resident set size= 87820 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 26461 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 56 involuntary context switches= 115 runsolver used 0.008 second user time and 0.016001 second system time The end