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/25.runsolver.aptitude aptitude -s -y --without-recommends install librmail-ruby1.8 python2.3-tz libbonobo-activation-dev fsviewer amrita 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.06 1.08 1.02 2/55 23118 /proc/meminfo: memFree=864444/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=3152 CPUtime=0 /proc/23118/stat : 23118 (runsolver) R 23117 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28830013 3227648 32 18446744073709551615 134512640 134586868 4288158288 4288156336 4151489584 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.119863 s] /proc/loadavg: 1.06 1.08 1.02 2/55 23118 /proc/meminfo: memFree=864444/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=100508 CPUtime=0.11 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 10535 1709 0 0 8 2 1 0 20 0 1 0 28830013 102920192 10336 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421120928 140086081648532 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 25127 10336 9162 1052 0 1122 0 Current children cumulated CPU time (s) 0.11 Current children cumulated vsize (KiB) 100508 [startup+0.200276 s] /proc/loadavg: 1.06 1.08 1.02 2/55 23118 /proc/meminfo: memFree=864444/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=100508 CPUtime=0.19 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 10605 1709 0 0 16 2 1 0 20 0 1 0 28830013 102920192 10406 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421120928 140086081644349 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 25127 10406 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 100508 [startup+0.300263 s] /proc/loadavg: 1.06 1.08 1.02 2/55 23118 /proc/meminfo: memFree=864444/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=111108 CPUtime=0.29 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 13340 1709 0 0 26 2 1 0 20 0 1 0 28830013 113774592 13133 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121312 140086087392784 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 27777 13133 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.700196 s] /proc/loadavg: 1.06 1.08 1.02 2/55 23118 /proc/meminfo: memFree=864444/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=123288 CPUtime=0.69 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 17028 1709 0 0 64 4 1 0 20 0 2 0 28830013 126246912 14302 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421125448 140086081644031 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 30822 14302 9482 1052 0 6817 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 123288 [startup+1.50023 s] /proc/loadavg: 1.06 1.08 1.02 2/57 23123 /proc/meminfo: memFree=836288/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=132520 CPUtime=1.49 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 19445 1709 0 0 144 4 1 0 20 0 2 0 28830013 135700480 16715 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421116824 140086044313853 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 33130 16715 9585 1052 0 9125 0 [pid=23118/tid=23123] ppid=23117 vsize=132520 CPUtime=0.01 /proc/23118/task/23123/stat : 23123 (aptitude) S 23117 23118 17863 34816 17863 4202560 4 1709 0 0 0 0 1 0 20 0 2 0 28830075 135700480 16715 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977630720 140086055547604 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 132520 [startup+3.10024 s] /proc/loadavg: 1.06 1.08 1.02 2/57 23124 /proc/meminfo: memFree=835048/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=135116 CPUtime=3.08 /proc/23118/stat : 23118 (aptitude) S 23117 23118 17863 34816 17863 4202496 21188 2207 0 0 297 10 1 0 20 0 2 0 28830013 138358784 17505 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121424 140086055548491 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 33779 17505 9694 1052 0 9774 0 [pid=23118/tid=23123] ppid=23117 vsize=135116 CPUtime=0.02 /proc/23118/task/23123/stat : 23123 (aptitude) R 23117 23118 17863 34816 17863 4202560 605 2207 0 0 1 0 1 0 20 0 2 0 28830075 138358784 17505 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977622392 140086044299194 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) 135116 [startup+6.30024 s] /proc/loadavg: 1.05 1.08 1.02 2/57 23124 /proc/meminfo: memFree=792392/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=247384 CPUtime=6.27 /proc/23118/stat : 23118 (aptitude) S 23117 23118 17863 34816 17863 4202496 33583 2207 0 0 612 14 1 0 20 0 2 0 28830013 253321216 29175 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121424 140086055548491 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 61846 29175 9700 1052 0 37841 0 [pid=23118/tid=23123] ppid=23117 vsize=247384 CPUtime=3.21 /proc/23118/task/23123/stat : 23123 (aptitude) R 23117 23118 17863 34816 17863 4202560 12998 2207 0 0 316 4 1 0 20 0 2 0 28830075 253321216 29175 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977622088 140086053112811 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 247384 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.05 1.08 1.02 2/57 23124 /proc/meminfo: memFree=792392/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=247648 CPUtime=6.36 /proc/23118/stat : 23118 (aptitude) S 23117 23118 17863 34816 17863 4202496 33656 2207 0 0 621 14 1 0 20 0 2 0 28830013 253591552 29248 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121424 140086055548491 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 61912 29248 9700 1052 0 37907 0 [pid=23118/tid=23123] ppid=23117 vsize=247648 CPUtime=3.31 /proc/23118/task/23123/stat : 23123 (aptitude) R 23117 23118 17863 34816 17863 4202560 13071 2207 0 0 326 4 1 0 20 0 2 0 28830075 253591552 29248 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977622040 140086044313927 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) 247648 [startup+9.6002 s] /proc/loadavg: 1.05 1.08 1.02 2/57 23124 /proc/meminfo: memFree=773792/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=268436 CPUtime=9.55 /proc/23118/stat : 23118 (aptitude) S 23117 23118 17863 34816 17863 4202496 38997 2207 0 0 937 17 1 0 20 0 2 0 28830013 274878464 34445 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121424 140086055548491 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 67109 34445 9700 1052 0 43104 0 [pid=23118/tid=23123] ppid=23117 vsize=268436 CPUtime=6.49 /proc/23118/task/23123/stat : 23123 (aptitude) R 23117 23118 17863 34816 17863 4202560 18412 2207 0 0 641 7 1 0 20 0 2 0 28830075 274878464 34445 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977624248 140086089430128 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 9.55 Current children cumulated vsize (KiB) 268436 [startup+10.4002 s] /proc/loadavg: 1.05 1.08 1.02 2/57 23124 /proc/meminfo: memFree=762136/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=275828 CPUtime=10.35 /proc/23118/stat : 23118 (aptitude) S 23117 23118 17863 34816 17863 4202496 40837 2207 0 0 1016 18 1 0 20 0 2 0 28830013 282447872 36284 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121424 140086055548491 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 68957 36284 9700 1052 0 44952 0 [pid=23118/tid=23123] ppid=23117 vsize=275828 CPUtime=7.29 /proc/23118/task/23123/stat : 23123 (aptitude) R 23117 23118 17863 34816 17863 4202560 20252 2207 0 0 720 8 1 0 20 0 2 0 28830075 282447872 36284 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977624248 140086089479212 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.35 Current children cumulated vsize (KiB) 275828 [startup+10.8002 s] /proc/loadavg: 1.05 1.08 1.02 2/57 23124 /proc/meminfo: memFree=762136/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=276808 CPUtime=10.74 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 43743 2207 0 0 1055 18 1 0 20 0 2 0 28830013 283451392 36648 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121864 140086089009940 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 69202 36648 9749 1052 0 45190 0 [pid=23118/tid=23123] ppid=23117 vsize=276808 CPUtime=7.41 /proc/23118/task/23123/stat : 23123 (aptitude) S 23117 23118 17863 34816 17863 4202560 20479 2207 0 0 732 8 1 0 20 0 2 0 28830075 283451392 36648 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977630720 140086055547604 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) 276808 [startup+11.0002 s] /proc/loadavg: 1.05 1.07 1.02 2/57 23125 /proc/meminfo: memFree=755432/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=276808 CPUtime=10.94 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 43931 2707 0 0 1071 22 1 0 20 0 2 0 28830013 283451392 36746 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421120984 140086044647493 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 69202 36746 9749 1052 0 45190 0 [pid=23118/tid=23123] ppid=23117 vsize=276808 CPUtime=7.41 /proc/23118/task/23123/stat : 23123 (aptitude) S 23117 23118 17863 34816 17863 4202560 20479 2707 0 0 732 8 1 0 20 0 2 0 28830075 283451392 36746 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977630720 140086055547604 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.94 Current children cumulated vsize (KiB) 276808 [startup+11.1031 s] /proc/loadavg: 1.05 1.07 1.02 2/57 23125 /proc/meminfo: memFree=755432/1022884 swapFree=0/0 [pid=23118] ppid=23117 vsize=276808 CPUtime=11.04 /proc/23118/stat : 23118 (aptitude) R 23117 23118 17863 34816 17863 4202496 44137 2707 0 0 1077 26 1 0 20 0 2 0 28830013 283451392 36647 18446744073709551615 140086086803456 140086091110808 140733421129664 140733421121480 140086044647536 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23118/statm: 69202 36647 9749 1052 0 45190 0 [pid=23118/tid=23123] ppid=23117 vsize=276808 CPUtime=7.41 /proc/23118/task/23123/stat : 23123 (aptitude) S 23117 23118 17863 34816 17863 4202560 20479 2707 0 0 732 8 1 0 20 0 2 0 28830075 283451392 36647 18446744073709551615 140086086803456 140086091110808 140733421129664 140085977630720 140086055547604 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.04 Current children cumulated vsize (KiB) 276808 Child status: 0 Real time (s): 11.1669 CPU time (s): 11.1207 CPU user time (s): 10.8127 CPU system time (s): 0.308019 CPU usage (%): 99.5863 Max. virtual memory (cumulated for all children) (KiB): 276808 getrusage(RUSAGE_CHILDREN,...) data: user time used= 10.8127 system time used= 0.308019 maximum resident set size= 147504 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 47342 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= 77 involuntary context switches= 238 runsolver used 0 second user time and 0.056003 second system time The end