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/138.runsolver.aptitude aptitude -s -y --without-recommends remove psutils libtiff4 libxtst6 libkrb53 synaptic 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: 0.96 1.05 1.03 2/55 24538 /proc/meminfo: memFree=864644/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=3152 CPUtime=0 /proc/24538/stat : 24538 (runsolver) R 24537 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29233852 3227648 32 18446744073709551615 134512640 134586868 4292055888 4292053936 4151538736 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.162705 s] /proc/loadavg: 0.96 1.05 1.03 2/55 24538 /proc/meminfo: memFree=864644/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=100508 CPUtime=0.14 /proc/24538/stat : 24538 (aptitude) R 24537 24538 17863 34816 17863 4202496 10602 1708 0 0 12 2 0 0 20 0 1 0 29233852 102920192 10400 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272436560 139893276169704 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 25127 10400 9225 1052 0 1122 0 Current children cumulated CPU time (s) 0.14 Current children cumulated vsize (KiB) 100508 [startup+0.200289 s] /proc/loadavg: 0.96 1.05 1.03 2/55 24538 /proc/meminfo: memFree=864644/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=100508 CPUtime=0.18 /proc/24538/stat : 24538 (aptitude) R 24537 24538 17863 34816 17863 4202496 10609 1708 0 0 16 2 0 0 20 0 1 0 29233852 102920192 10407 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272436560 139893276170734 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 100508 [startup+0.300271 s] /proc/loadavg: 0.96 1.05 1.03 2/55 24538 /proc/meminfo: memFree=864644/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=111108 CPUtime=0.29 /proc/24538/stat : 24538 (aptitude) R 24537 24538 17863 34816 17863 4202496 13015 1708 0 0 26 3 0 0 20 0 1 0 29233852 113774592 12805 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272436888 139893239546476 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 27777 12805 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.700207 s] /proc/loadavg: 0.96 1.05 1.03 2/55 24538 /proc/meminfo: memFree=864644/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=124776 CPUtime=0.68 /proc/24538/stat : 24538 (aptitude) R 24537 24538 17863 34816 17863 4202496 17345 1708 0 0 63 5 0 0 20 0 2 0 29233852 127770624 14616 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272437336 139893284364871 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 31194 14616 9514 1052 0 7189 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 124776 [startup+1.50024 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24543 /proc/meminfo: memFree=836736/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=131940 CPUtime=1.48 /proc/24538/stat : 24538 (aptitude) R 24537 24538 17863 34816 17863 4202496 19303 1708 0 0 142 6 0 0 20 0 2 0 29233852 135106560 16571 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272433416 139893284374932 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 32985 16571 9568 1052 0 8980 0 [pid=24538/tid=24543] ppid=24537 vsize=131940 CPUtime=0 /proc/24538/task/24543/stat : 24543 (aptitude) S 24537 24538 17863 34816 17863 4202560 4 1708 0 0 0 0 0 0 20 0 2 0 29233917 135106560 16571 18446744073709551615 139893281329152 139893285636504 140735272445296 139893172156416 139893250073300 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) 131940 [startup+3.10024 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24543 /proc/meminfo: memFree=835992/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=158512 CPUtime=3.07 /proc/24538/stat : 24538 (aptitude) S 24537 24538 17863 34816 17863 4202496 26038 1708 0 0 299 8 0 0 20 0 2 0 29233852 162316288 23305 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272437056 139893250074187 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 39628 23305 9660 1052 0 15623 0 [pid=24538/tid=24543] ppid=24537 vsize=158512 CPUtime=0.55 /proc/24538/task/24543/stat : 24543 (aptitude) R 24537 24538 17863 34816 17863 4202560 6597 1708 0 0 53 2 0 0 20 0 2 0 29233917 162316288 23305 18446744073709551615 139893281329152 139893285636504 140735272445296 139893172150072 139893283975450 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) 158512 Solver just ended. Dumping a history of the last processes samples [startup+3.20032 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24543 /proc/meminfo: memFree=835992/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=162736 CPUtime=3.17 /proc/24538/stat : 24538 (aptitude) S 24537 24538 17863 34816 17863 4202496 27093 1708 0 0 309 8 0 0 20 0 2 0 29233852 166641664 24360 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272437056 139893250074187 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 40684 24360 9660 1052 0 16679 0 [pid=24538/tid=24543] ppid=24537 vsize=162736 CPUtime=0.65 /proc/24538/task/24543/stat : 24543 (aptitude) R 24537 24538 17863 34816 17863 4202560 7652 1708 0 0 63 2 0 0 20 0 2 0 29233917 166641664 24360 18446744073709551615 139893281329152 139893285636504 140735272445296 139893172146664 139893284016003 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) 162736 [startup+4.80024 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24543 /proc/meminfo: memFree=755392/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=216144 CPUtime=4.76 /proc/24538/stat : 24538 (aptitude) S 24537 24538 17863 34816 17863 4202496 40431 1708 0 0 464 12 0 0 20 0 2 0 29233852 221331456 37698 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272437056 139893250074187 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 54036 37698 9662 1052 0 30031 0 [pid=24538/tid=24543] ppid=24537 vsize=216144 CPUtime=2.24 /proc/24538/task/24543/stat : 24543 (aptitude) R 24537 24538 17863 34816 17863 4202560 20990 1708 0 0 218 6 0 0 20 0 2 0 29233917 221331456 37698 18446744073709551615 139893281329152 139893285636504 140735272445296 139893172150664 139893283913982 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.76 Current children cumulated vsize (KiB) 216144 [startup+5.20025 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24543 /proc/meminfo: memFree=755392/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=217816 CPUtime=5.15 /proc/24538/stat : 24538 (aptitude) R 24537 24538 17863 34816 17863 4202496 40924 1708 0 0 503 12 0 0 20 0 2 0 29233852 223043584 38189 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272435128 139893276182502 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 54454 38189 9712 1052 0 30442 0 [pid=24538/tid=24543] ppid=24537 vsize=217816 CPUtime=2.29 /proc/24538/task/24543/stat : 24543 (aptitude) S 24537 24538 17863 34816 17863 4202560 21256 1708 0 0 223 6 0 0 20 0 2 0 29233917 223043584 38189 18446744073709551615 139893281329152 139893285636504 140735272445296 139893172156416 139893250073300 0 134217728 4096 0 0 0 0 -1 0 0 0 1 0 0 Current children cumulated CPU time (s) 5.15 Current children cumulated vsize (KiB) 217816 [startup+5.40098 s] /proc/loadavg: 0.96 1.05 1.03 2/57 24543 /proc/meminfo: memFree=755392/1022884 swapFree=0/0 [pid=24538] ppid=24537 vsize=131532 CPUtime=5.35 /proc/24538/stat : 24538 (aptitude) R 24537 24538 17863 34816 17863 4202496 40945 1708 0 0 521 14 0 0 20 0 1 0 29233852 134688768 12571 18446744073709551615 139893281329152 139893285636504 140735272445296 140735272444856 139893239195114 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24538/statm: 32883 12571 1478 1052 0 17139 0 Current children cumulated CPU time (s) 5.35 Current children cumulated vsize (KiB) 131532 Child status: 0 Real time (s): 5.41283 CPU time (s): 5.38034 CPU user time (s): 5.22033 CPU system time (s): 0.16001 CPU usage (%): 99.3996 Max. virtual memory (cumulated for all children) (KiB): 217816 getrusage(RUSAGE_CHILDREN,...) data: user time used= 5.22033 system time used= 0.16001 maximum resident set size= 152800 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 42709 page faults= 0 swaps= 0 block input operations= 0 block output operations= 56 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 63 involuntary context switches= 136 runsolver used 0.008 second user time and 0.024001 second system time The end