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/32.runsolver.aptitude aptitude -s -y --without-recommends install libotr1-bin archivemail cbmlink cccd libasound2-plugins 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.10 1.06 1.01 2/55 23189 /proc/meminfo: memFree=869716/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=3152 CPUtime=0 /proc/23189/stat : 23189 (runsolver) R 23188 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28862796 3227648 33 18446744073709551615 134512640 134586868 4288198992 4288197040 4152001584 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.131891 s] /proc/loadavg: 1.10 1.06 1.01 2/55 23189 /proc/meminfo: memFree=869716/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=100508 CPUtime=0.12 /proc/23189/stat : 23189 (aptitude) R 23188 23189 17863 34816 17863 4202496 10573 1710 0 0 9 3 0 0 20 0 1 0 28862796 102920192 10375 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092400 140088094509328 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 25127 10375 9200 1052 0 1122 0 Current children cumulated CPU time (s) 0.12 Current children cumulated vsize (KiB) 100508 [startup+0.200284 s] /proc/loadavg: 1.10 1.06 1.01 2/55 23189 /proc/meminfo: memFree=869716/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=100508 CPUtime=0.19 /proc/23189/stat : 23189 (aptitude) R 23188 23189 17863 34816 17863 4202496 10605 1710 0 0 16 3 0 0 20 0 1 0 28862796 102920192 10407 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092400 140088094509550 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 100508 [startup+0.300267 s] /proc/loadavg: 1.10 1.06 1.01 2/55 23189 /proc/meminfo: memFree=869716/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=111108 CPUtime=0.29 /proc/23189/stat : 23189 (aptitude) R 23188 23189 17863 34816 17863 4202496 12507 1710 0 0 26 3 0 0 20 0 1 0 28862796 113774592 12301 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092728 140088101799507 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 27777 12301 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.70019 s] /proc/loadavg: 1.10 1.06 1.01 2/55 23189 /proc/meminfo: memFree=869716/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=123288 CPUtime=0.68 /proc/23189/stat : 23189 (aptitude) R 23188 23189 17863 34816 17863 4202496 17028 1710 0 0 63 5 0 0 20 0 2 0 28862796 126246912 14303 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125096920 140088094363376 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 30822 14303 9482 1052 0 6817 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123288 [startup+1.50022 s] /proc/loadavg: 1.10 1.06 1.01 2/57 23194 /proc/meminfo: memFree=841436/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=132412 CPUtime=1.47 /proc/23189/stat : 23189 (aptitude) R 23188 23189 17863 34816 17863 4202496 19446 1710 0 0 142 5 0 0 20 0 2 0 28862796 135589888 16716 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125091488 140088094491920 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 33103 16716 9585 1052 0 9098 0 [pid=23189/tid=23194] ppid=23188 vsize=132412 CPUtime=0 /proc/23189/task/23194/stat : 23194 (aptitude) S 23188 23189 17863 34816 17863 4202560 4 1710 0 0 0 0 0 0 20 0 2 0 28862861 135589888 16716 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990495232 140088068412116 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) 132412 [startup+3.10024 s] /proc/loadavg: 1.10 1.06 1.01 2/57 23195 /proc/meminfo: memFree=839948/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=139200 CPUtime=3.08 /proc/23189/stat : 23189 (aptitude) S 23188 23189 17863 34816 17863 4202496 22192 2213 0 0 298 9 0 1 20 0 2 0 28862796 142540800 18507 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092896 140088068413003 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 34800 18507 9697 1052 0 10795 0 [pid=23189/tid=23194] ppid=23188 vsize=139200 CPUtime=0.17 /proc/23189/task/23194/stat : 23194 (aptitude) R 23188 23189 17863 34816 17863 4202560 1610 2213 0 0 16 0 0 1 20 0 2 0 28862861 142540800 18507 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990486920 140088102301111 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) 139200 [startup+6.30025 s] /proc/loadavg: 1.09 1.05 1.01 2/57 23195 /proc/meminfo: memFree=795680/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=246448 CPUtime=6.26 /proc/23189/stat : 23189 (aptitude) S 23188 23189 17863 34816 17863 4202496 33344 2213 0 0 611 14 0 1 20 0 2 0 28862796 252362752 28945 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092896 140088068413003 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 61612 28945 9700 1052 0 37607 0 [pid=23189/tid=23194] ppid=23188 vsize=246448 CPUtime=3.36 /proc/23189/task/23194/stat : 23194 (aptitude) R 23188 23189 17863 34816 17863 4202560 12760 2213 0 0 330 5 0 1 20 0 2 0 28862861 252362752 28945 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990486552 140088095068722 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) 246448 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.09 1.05 1.01 2/57 23195 /proc/meminfo: memFree=795680/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=246976 CPUtime=6.36 /proc/23189/stat : 23189 (aptitude) S 23188 23189 17863 34816 17863 4202496 33469 2213 0 0 621 14 0 1 20 0 2 0 28862796 252903424 29070 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092896 140088068413003 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 61744 29070 9700 1052 0 37739 0 [pid=23189/tid=23194] ppid=23188 vsize=246976 CPUtime=3.46 /proc/23189/task/23194/stat : 23194 (aptitude) R 23188 23189 17863 34816 17863 4202560 12885 2213 0 0 340 5 0 1 20 0 2 0 28862861 252903424 29070 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990486600 140088100261536 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) 246976 [startup+9.60023 s] /proc/loadavg: 1.08 1.05 1.01 2/57 23195 /proc/meminfo: memFree=777080/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=269192 CPUtime=9.54 /proc/23189/stat : 23189 (aptitude) S 23188 23189 17863 34816 17863 4202496 39185 2213 0 0 937 16 0 1 20 0 2 0 28862796 275652608 34629 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092896 140088068413003 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 67298 34629 9700 1052 0 43293 0 [pid=23189/tid=23194] ppid=23188 vsize=269192 CPUtime=6.65 /proc/23189/task/23194/stat : 23194 (aptitude) R 23188 23189 17863 34816 17863 4202560 18601 2213 0 0 656 8 0 1 20 0 2 0 28862861 275652608 34629 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990486552 140088102431973 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 9.54 Current children cumulated vsize (KiB) 269192 [startup+10.4002 s] /proc/loadavg: 1.08 1.05 1.01 2/57 23195 /proc/meminfo: memFree=766788/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=275660 CPUtime=10.34 /proc/23189/stat : 23189 (aptitude) S 23188 23189 17863 34816 17863 4202496 40812 2213 0 0 1016 17 0 1 20 0 2 0 28862796 282275840 36254 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092896 140088068413003 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 68915 36254 9700 1052 0 44910 0 [pid=23189/tid=23194] ppid=23188 vsize=275660 CPUtime=7.43 /proc/23189/task/23194/stat : 23194 (aptitude) R 23188 23189 17863 34816 17863 4202560 20228 2213 0 0 734 8 0 1 20 0 2 0 28862861 282275840 36254 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990486552 140088057178208 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.34 Current children cumulated vsize (KiB) 275660 [startup+10.8002 s] /proc/loadavg: 1.08 1.05 1.01 2/57 23195 /proc/meminfo: memFree=766788/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=276776 CPUtime=10.74 /proc/23189/stat : 23189 (aptitude) R 23188 23189 17863 34816 17863 4202496 42082 2213 0 0 1055 18 0 1 20 0 2 0 28862796 283418624 36685 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125090968 140088095067738 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 69194 36685 9749 1052 0 45182 0 [pid=23189/tid=23194] ppid=23188 vsize=276776 CPUtime=7.58 /proc/23189/task/23194/stat : 23194 (aptitude) S 23188 23189 17863 34816 17863 4202560 20482 2213 0 0 748 9 0 1 20 0 2 0 28862861 283418624 36685 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990495232 140088068412116 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.74 Current children cumulated vsize (KiB) 276776 [startup+11.2002 s] /proc/loadavg: 1.08 1.05 1.01 2/57 23195 /proc/meminfo: memFree=760960/1022884 swapFree=0/0 [pid=23189] ppid=23188 vsize=276776 CPUtime=11.15 /proc/23189/stat : 23189 (aptitude) R 23188 23189 17863 34816 17863 4202496 44140 2713 0 0 1089 24 0 2 20 0 2 0 28862796 283418624 36873 18446744073709551615 140088099667968 140088103975320 140735125101136 140735125092952 140088057512005 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23189/statm: 69194 36873 9749 1052 0 45182 0 [pid=23189/tid=23194] ppid=23188 vsize=276776 CPUtime=7.59 /proc/23189/task/23194/stat : 23194 (aptitude) S 23188 23189 17863 34816 17863 4202560 20482 2713 0 0 748 9 0 2 20 0 2 0 28862861 283418624 36873 18446744073709551615 140088099667968 140088103975320 140735125101136 140087990495232 140088068412116 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.15 Current children cumulated vsize (KiB) 276776 Child status: 0 Real time (s): 11.2608 CPU time (s): 11.2167 CPU user time (s): 10.9167 CPU system time (s): 0.300018 CPU usage (%): 99.6087 Max. virtual memory (cumulated for all children) (KiB): 276776 getrusage(RUSAGE_CHILDREN,...) data: user time used= 10.9167 system time used= 0.300018 maximum resident set size= 147492 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 47350 page faults= 0 swaps= 0 block input operations= 0 block output operations= 136 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 78 involuntary context switches= 244 runsolver used 0.008 second user time and 0.048003 second system time The end