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/70.runsolver.aptitude aptitude -s -y --without-recommends install libformsgl1 dh-make bigloo-doc libauthen-sasl-cyrus-perl clamav 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.22 1.07 0.99 2/55 21695 /proc/meminfo: memFree=978284/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=3152 CPUtime=0 /proc/21695/stat : 21695 (runsolver) R 21694 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28542180 3227648 33 18446744073709551615 134512640 134586868 4292224432 4292222480 4151387184 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/21695/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.185956 s] /proc/loadavg: 1.22 1.07 0.99 2/55 21695 /proc/meminfo: memFree=978284/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=30864 CPUtime=0 /proc/21695/stat : 21695 (aptitude) D 21694 21695 17863 34816 17863 4202496 160 0 12 0 0 0 0 0 20 0 1 0 28542180 31604736 82 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878592472 139680841085718 0 0 0 0 0 0 0 17 0 0 0 17 0 0 /proc/21695/statm: 7716 82 52 1052 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 30864 [startup+0.200374 s] /proc/loadavg: 1.22 1.07 0.99 2/55 21695 /proc/meminfo: memFree=978284/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=33024 CPUtime=0 /proc/21695/stat : 21695 (aptitude) D 21694 21695 17863 34816 17863 4202496 163 0 13 0 0 0 0 0 20 0 1 0 28542180 33816576 86 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878592280 139680841086499 0 0 0 0 0 0 0 17 0 0 0 18 0 0 /proc/21695/statm: 8256 86 55 1052 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 33024 [startup+0.300229 s] /proc/loadavg: 1.22 1.07 0.99 2/55 21695 /proc/meminfo: memFree=978284/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=54860 CPUtime=0 /proc/21695/stat : 21695 (aptitude) R 21694 21695 17863 34816 17863 4202496 583 0 23 0 0 0 0 0 20 0 1 0 28542180 56176640 505 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878595064 139680841036828 0 0 0 0 0 0 0 17 0 0 0 29 0 0 /proc/21695/statm: 13715 505 413 1052 0 73 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 54860 [startup+0.700305 s] /proc/loadavg: 1.22 1.07 0.99 2/55 21695 /proc/meminfo: memFree=978284/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=89152 CPUtime=0.01 /proc/21695/stat : 21695 (aptitude) D 21694 21695 17863 34816 17863 4202496 2153 1705 63 4 1 0 0 0 20 0 1 0 28542180 91291648 2013 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878587328 139680838277018 0 134217728 4096 0 0 0 0 17 0 0 0 62 0 0 /proc/21695/statm: 22288 2013 1102 1052 0 858 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 89152 [startup+1.50032 s] /proc/loadavg: 1.22 1.07 0.99 1/56 21699 /proc/meminfo: memFree=965868/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=89152 CPUtime=0.03 /proc/21695/stat : 21695 (aptitude) D 21694 21695 17863 34816 17863 4202496 3011 1705 212 4 2 1 0 0 20 0 1 0 28542180 91291648 3020 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878587328 139680838085091 0 134217728 4096 0 0 0 0 17 0 0 0 141 0 0 /proc/21695/statm: 22288 3020 2109 1052 0 858 0 Current children cumulated CPU time (s) 0.03 Current children cumulated vsize (KiB) 89152 [startup+3.10022 s] /proc/loadavg: 1.21 1.07 0.99 1/56 21699 /proc/meminfo: memFree=943548/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=114212 CPUtime=0.93 /proc/21695/stat : 21695 (aptitude) R 21694 21695 17863 34816 17863 4202496 13507 1705 278 4 88 5 0 0 20 0 2 0 28542180 116953088 12153 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878586152 139680800722881 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 212 0 0 /proc/21695/statm: 28553 12153 7014 1052 0 7123 0 Current children cumulated CPU time (s) 0.93 Current children cumulated vsize (KiB) 114212 heavy processes: [startup+6.30023 s] /proc/loadavg: 1.21 1.07 0.99 2/57 21701 /proc/meminfo: memFree=855996/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=223376 CPUtime=4.09 /proc/21695/stat : 21695 (aptitude) S 21694 21695 17863 34816 17863 4202496 26162 2200 278 6 398 11 0 0 20 0 2 0 28542180 228737024 23190 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878587616 139680811972171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 212 0 0 /proc/21695/statm: 55844 23190 7122 1052 0 34414 0 [pid=21695/tid=21700] ppid=21694 vsize=223376 CPUtime=2.21 /proc/21695/task/21700/stat : 21700 (aptitude) R 21694 21695 17863 34816 17863 4202560 11902 2200 0 6 216 5 0 0 20 0 2 0 28542444 228737024 23190 18446744073709551615 139680843227136 139680847534488 140735878595856 139680746626872 139680845934564 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.09 Current children cumulated vsize (KiB) 223376 heavy processes: Solver just ended. Dumping a history of the last processes samples [startup+6.40347 s] /proc/loadavg: 1.21 1.07 0.99 2/57 21701 /proc/meminfo: memFree=848060/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=224572 CPUtime=4.19 /proc/21695/stat : 21695 (aptitude) S 21694 21695 17863 34816 17863 4202496 26441 2200 278 6 408 11 0 0 20 0 2 0 28542180 229961728 23469 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878587616 139680811972171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 212 0 0 /proc/21695/statm: 56143 23469 7122 1052 0 34713 0 [pid=21695/tid=21700] ppid=21694 vsize=224572 CPUtime=2.31 /proc/21695/task/21700/stat : 21700 (aptitude) R 21694 21695 17863 34816 17863 4202560 12181 2200 0 6 226 5 0 0 20 0 2 0 28542444 229961728 23469 18446744073709551615 139680843227136 139680847534488 140735878595856 139680746626824 139680846012815 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.19 Current children cumulated vsize (KiB) 224572 [startup+8.00024 s] /proc/loadavg: 1.19 1.07 0.99 2/57 21701 /proc/meminfo: memFree=832312/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=243876 CPUtime=5.77 /proc/21695/stat : 21695 (aptitude) S 21694 21695 17863 34816 17863 4202496 31288 2200 278 6 564 13 0 0 20 0 2 0 28542180 249729024 28286 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878587616 139680811972171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 212 0 0 /proc/21695/statm: 60969 28286 7122 1052 0 39539 0 [pid=21695/tid=21700] ppid=21694 vsize=243876 CPUtime=3.9 /proc/21695/task/21700/stat : 21700 (aptitude) R 21694 21695 17863 34816 17863 4202560 17028 2200 0 6 383 7 0 0 20 0 2 0 28542444 249729024 28286 18446744073709551615 139680843227136 139680847534488 140735878595856 139680746626920 139680800737761 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 5.77 Current children cumulated vsize (KiB) 243876 [startup+8.80023 s] /proc/loadavg: 1.19 1.07 0.99 2/57 21701 /proc/meminfo: memFree=819168/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=252192 CPUtime=6.57 /proc/21695/stat : 21695 (aptitude) S 21694 21695 17863 34816 17863 4202496 33395 2200 278 6 643 14 0 0 20 0 2 0 28542180 258244608 30388 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878587616 139680811972171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 212 0 0 /proc/21695/statm: 63048 30388 7123 1052 0 41618 0 [pid=21695/tid=21700] ppid=21694 vsize=252192 CPUtime=4.7 /proc/21695/task/21700/stat : 21700 (aptitude) R 21694 21695 17863 34816 17863 4202560 19135 2200 0 6 462 8 0 0 20 0 2 0 28542444 258244608 30388 18446744073709551615 139680843227136 139680847534488 140735878595856 139680746624664 139680845458751 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.57 Current children cumulated vsize (KiB) 252192 [startup+9.20026 s] /proc/loadavg: 1.19 1.07 0.99 2/57 21701 /proc/meminfo: memFree=819168/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=256020 CPUtime=6.96 /proc/21695/stat : 21695 (aptitude) S 21694 21695 17863 34816 17863 4202496 34346 2200 278 6 682 14 0 0 20 0 2 0 28542180 262164480 31339 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878587616 139680811972171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 212 0 0 /proc/21695/statm: 64005 31339 7123 1052 0 42575 0 [pid=21695/tid=21700] ppid=21694 vsize=256020 CPUtime=5.09 /proc/21695/task/21700/stat : 21700 (aptitude) R 21694 21695 17863 34816 17863 4202560 20086 2200 0 6 501 8 0 0 20 0 2 0 28542444 262164480 31339 18446744073709551615 139680843227136 139680847534488 140735878595856 139680746624888 139680845874142 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.96 Current children cumulated vsize (KiB) 256020 [startup+9.60024 s] /proc/loadavg: 1.19 1.07 0.99 2/57 21701 /proc/meminfo: memFree=819168/1022884 swapFree=0/0 [pid=21695] ppid=21694 vsize=195144 CPUtime=7.38 /proc/21695/stat : 21695 (aptitude) R 21694 21695 17863 34816 17863 4202496 36449 2699 278 6 718 18 1 1 20 0 1 0 28542180 199827456 16240 18446744073709551615 139680843227136 139680847534488 140735878595856 140735878592936 139680845344704 0 134217728 4096 0 0 0 0 17 0 0 0 212 0 0 /proc/21695/statm: 48786 16240 1496 1052 0 33042 0 Current children cumulated CPU time (s) 7.38 Current children cumulated vsize (KiB) 195144 Child status: 0 Real time (s): 9.61682 CPU time (s): 7.40846 CPU user time (s): 7.19645 CPU system time (s): 0.212013 CPU usage (%): 77.0365 Max. virtual memory (cumulated for all children) (KiB): 256260 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.19645 system time used= 0.212013 maximum resident set size= 126132 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 39242 page faults= 284 swaps= 0 block input operations= 130848 block output operations= 8 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 1357 involuntary context switches= 185 runsolver used 0.012 second user time and 0.044002 second system time The end