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/159.runsolver.aptitude aptitude -s -y --without-recommends remove libmng-dev libksba8 libboost-python1.32.0 kpersonalizer kdevelop3-data 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.12 1.06 1.02 2/55 24689 /proc/meminfo: memFree=869692/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=3152 CPUtime=0 /proc/24689/stat : 24689 (runsolver) R 24688 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29257617 3227648 33 18446744073709551615 134512640 134586868 4287400224 4287398272 4152202288 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.151127 s] /proc/loadavg: 1.12 1.06 1.02 2/55 24689 /proc/meminfo: memFree=869692/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=100508 CPUtime=0.13 /proc/24689/stat : 24689 (aptitude) R 24688 24689 17863 34816 17863 4202496 10590 1710 0 0 10 3 0 0 20 0 1 0 29257617 102920192 10391 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404115760 139902333298580 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 25127 10391 9216 1052 0 1122 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 100508 [startup+0.200296 s] /proc/loadavg: 1.12 1.06 1.02 2/55 24689 /proc/meminfo: memFree=869692/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=100508 CPUtime=0.19 /proc/24689/stat : 24689 (aptitude) R 24688 24689 17863 34816 17863 4202496 10606 1710 0 0 15 4 0 0 20 0 1 0 29257617 102920192 10407 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404115760 139902333294155 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 100508 [startup+0.300277 s] /proc/loadavg: 1.12 1.06 1.02 2/55 24689 /proc/meminfo: memFree=869692/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=111108 CPUtime=0.28 /proc/24689/stat : 24689 (aptitude) R 24688 24689 17863 34816 17863 4202496 12702 1710 0 0 24 4 0 0 20 0 1 0 29257617 113774592 12495 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404116088 139902296670828 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 27777 12495 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 111108 [startup+0.700223 s] /proc/loadavg: 1.12 1.06 1.02 2/55 24689 /proc/meminfo: memFree=869692/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=123288 CPUtime=0.68 /proc/24689/stat : 24689 (aptitude) R 24688 24689 17863 34816 17863 4202496 17025 1710 0 0 62 6 0 0 20 0 2 0 29257617 126246912 14299 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404118120 139902296670813 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 30822 14299 9478 1052 0 6817 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123288 [startup+1.50026 s] /proc/loadavg: 1.12 1.06 1.02 2/57 24694 /proc/meminfo: memFree=841784/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=131940 CPUtime=1.47 /proc/24689/stat : 24689 (aptitude) R 24688 24689 17863 34816 17863 4202496 19298 1710 0 0 141 6 0 0 20 0 2 0 29257617 135106560 16568 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404111656 139902295964019 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 32985 16568 9569 1052 0 8980 0 [pid=24689/tid=24694] ppid=24688 vsize=131940 CPUtime=0 /proc/24689/task/24694/stat : 24694 (aptitude) S 24688 24689 17863 34816 17863 4202560 4 1710 0 0 0 0 0 0 20 0 2 0 29257682 135106560 16568 18446744073709551615 139902338453504 139902342760856 140734404124496 139902229280768 139902307197652 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.10025 s] /proc/loadavg: 1.12 1.06 1.02 2/57 24694 /proc/meminfo: memFree=841164/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=144132 CPUtime=3.07 /proc/24689/stat : 24689 (aptitude) S 24688 24689 17863 34816 17863 4202496 22452 1710 0 0 301 6 0 0 20 0 2 0 29257617 147591168 19721 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404116256 139902307198539 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 36033 19721 9662 1052 0 12028 0 [pid=24689/tid=24694] ppid=24688 vsize=144132 CPUtime=0.54 /proc/24689/task/24694/stat : 24694 (aptitude) R 24688 24689 17863 34816 17863 4202560 3013 1710 0 0 54 0 0 0 20 0 2 0 29257682 147591168 19721 18446744073709551615 139902338453504 139902342760856 140734404124496 139902229276184 139902295964129 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) 144132 Solver just ended. Dumping a history of the last processes samples [startup+3.2003 s] /proc/loadavg: 1.12 1.06 1.02 2/57 24694 /proc/meminfo: memFree=841164/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=145056 CPUtime=3.17 /proc/24689/stat : 24689 (aptitude) S 24688 24689 17863 34816 17863 4202496 22676 1710 0 0 311 6 0 0 20 0 2 0 29257617 148537344 19945 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404116256 139902307198539 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 36264 19945 9662 1052 0 12259 0 [pid=24689/tid=24694] ppid=24688 vsize=145056 CPUtime=0.64 /proc/24689/task/24694/stat : 24694 (aptitude) R 24688 24689 17863 34816 17863 4202560 3237 1710 0 0 64 0 0 0 20 0 2 0 29257682 148537344 19945 18446744073709551615 139902338453504 139902342760856 140734404124496 139902229272440 139902304762859 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) 145056 [startup+4.00026 s] /proc/loadavg: 1.11 1.06 1.02 2/57 24694 /proc/meminfo: memFree=827524/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=151128 CPUtime=3.97 /proc/24689/stat : 24689 (aptitude) S 24688 24689 17863 34816 17863 4202496 24201 1710 0 0 390 7 0 0 20 0 2 0 29257617 154755072 21470 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404116256 139902307198539 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 37782 21470 9662 1052 0 13777 0 [pid=24689/tid=24694] ppid=24688 vsize=151128 CPUtime=1.44 /proc/24689/task/24694/stat : 24694 (aptitude) R 24688 24689 17863 34816 17863 4202560 4762 1710 0 0 143 1 0 0 20 0 2 0 29257682 154755072 21470 18446744073709551615 139902338453504 139902342760856 140734404124496 139902229270840 139902333277305 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) 151128 [startup+4.40025 s] /proc/loadavg: 1.11 1.06 1.02 2/57 24694 /proc/meminfo: memFree=819712/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=153636 CPUtime=4.36 /proc/24689/stat : 24689 (aptitude) S 24688 24689 17863 34816 17863 4202496 24828 1710 0 0 428 8 0 0 20 0 2 0 29257617 157323264 22097 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404116256 139902307198539 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 38409 22097 9662 1052 0 14404 0 [pid=24689/tid=24694] ppid=24688 vsize=153636 CPUtime=1.84 /proc/24689/task/24694/stat : 24694 (aptitude) R 24688 24689 17863 34816 17863 4202560 5389 1710 0 0 182 2 0 0 20 0 2 0 29257682 157323264 22097 18446744073709551615 139902338453504 139902342760856 140734404124496 139902229276264 139902341217150 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.36 Current children cumulated vsize (KiB) 153636 [startup+4.60025 s] /proc/loadavg: 1.11 1.06 1.02 2/57 24694 /proc/meminfo: memFree=819712/1022884 swapFree=0/0 [pid=24689] ppid=24688 vsize=154060 CPUtime=4.56 /proc/24689/stat : 24689 (aptitude) R 24688 24689 17863 34816 17863 4202496 24973 1710 0 0 448 8 0 0 20 0 2 0 29257617 157757440 22240 18446744073709551615 139902338453504 139902342760856 140734404124496 140734404112360 139902340659879 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24689/statm: 38515 22240 9711 1052 0 14503 0 [pid=24689/tid=24694] ppid=24688 vsize=154060 CPUtime=1.86 /proc/24689/task/24694/stat : 24694 (aptitude) S 24688 24689 17863 34816 17863 4202560 5478 1710 0 0 184 2 0 0 20 0 2 0 29257682 157757440 22240 18446744073709551615 139902338453504 139902342760856 140734404124496 139902229280768 139902307197652 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.56 Current children cumulated vsize (KiB) 154060 Child status: 0 Real time (s): 4.67033 CPU time (s): 4.65229 CPU user time (s): 4.54028 CPU system time (s): 0.112007 CPU usage (%): 99.6137 Max. virtual memory (cumulated for all children) (KiB): 154060 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.54028 system time used= 0.112007 maximum resident set size= 88976 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 26751 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= 57 involuntary context switches= 128 runsolver used 0 second user time and 0.028001 second system time The end