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/logs/78.runsolver.aptitude aptitude -s -y --without-recommends install lg-issue59 libroxen-smbauth tipa dcl holotz-castle-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 Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 0.99 0.72 0.33 2/55 19917 /proc/meminfo: memFree=244596/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=54860 CPUtime=0 /proc/19917/stat : 19917 (aptitude) R 19916 19917 17863 34816 17863 4202496 595 0 0 0 0 0 0 0 20 0 1 0 28201347 56176640 495 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716617864 139848295114690 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 13715 495 404 1052 0 73 0 [startup+0.183162 s] /proc/loadavg: 0.99 0.72 0.33 2/55 19917 /proc/meminfo: memFree=244596/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=86100 CPUtime=0.17 /proc/19917/stat : 19917 (aptitude) R 19916 19917 17863 34816 17863 4202496 7113 1709 0 0 15 2 0 0 20 0 1 0 28201347 88166400 6904 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716607800 139848292704880 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 21525 6904 4716 1052 0 2116 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 86100 [startup+0.200306 s] /proc/loadavg: 0.99 0.72 0.33 2/55 19917 /proc/meminfo: memFree=244596/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=87044 CPUtime=0.19 /proc/19917/stat : 19917 (aptitude) R 19916 19917 17863 34816 17863 4202496 7479 1709 0 0 17 2 0 0 20 0 1 0 28201347 89133056 7103 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716608168 139848300228465 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 21761 7103 4721 1052 0 2352 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 87044 [startup+0.300263 s] /proc/loadavg: 0.99 0.72 0.33 2/55 19917 /proc/meminfo: memFree=244596/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=90632 CPUtime=0.29 /proc/19917/stat : 19917 (aptitude) R 19916 19917 17863 34816 17863 4202496 8628 1709 0 0 26 3 0 0 20 0 1 0 28201347 92807168 7674 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716608088 139848266060144 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 22658 7674 4725 1052 0 3249 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 90632 [startup+0.70021 s] /proc/loadavg: 0.99 0.72 0.33 2/55 19917 /proc/meminfo: memFree=244596/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=100676 CPUtime=0.68 /proc/19917/stat : 19917 (aptitude) R 19916 19917 17863 34816 17863 4202496 10139 1709 0 0 64 4 0 0 20 0 2 0 28201347 103092224 8768 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716606424 139848298932426 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 25169 8768 4994 1052 0 5760 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 100676 [startup+1.50023 s] /proc/loadavg: 0.99 0.72 0.33 2/57 19923 /proc/meminfo: memFree=228832/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=110968 CPUtime=1.47 /proc/19917/stat : 19917 (aptitude) S 19916 19917 17863 34816 17863 4202496 13790 2211 0 0 141 6 0 0 20 0 2 0 28201347 113631232 11449 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716610416 139848266049099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 27742 11449 5099 1052 0 8333 0 [pid=19917/tid=19922] ppid=19916 vsize=110968 CPUtime=0.27 /proc/19917/task/19922/stat : 19922 (aptitude) R 19916 19917 17863 34816 17863 4202560 3083 2211 0 0 26 1 0 0 20 0 2 0 28201378 113631232 11449 18446744073709551615 139848297304064 139848301611416 140736716618656 139848213876536 139848254799662 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) 110968 [startup+3.10025 s] /proc/loadavg: 0.99 0.73 0.34 2/57 19923 /proc/meminfo: memFree=211108/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=127364 CPUtime=3.06 /proc/19917/stat : 19917 (aptitude) S 19916 19917 17863 34816 17863 4202496 17925 2211 0 0 298 8 0 0 20 0 2 0 28201347 130420736 15540 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716610416 139848266049099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 31841 15540 5100 1052 0 12432 0 [pid=19917/tid=19922] ppid=19916 vsize=127364 CPUtime=1.87 /proc/19917/task/19922/stat : 19922 (aptitude) R 19916 19917 17863 34816 17863 4202560 7217 2211 0 0 184 3 0 0 20 0 2 0 28201378 130420736 15540 18446744073709551615 139848297304064 139848301611416 140736716618656 139848213874200 139848298932581 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.06 Current children cumulated vsize (KiB) 127364 Solver just ended. Dumping a history of the last processes samples [startup+3.20032 s] /proc/loadavg: 0.99 0.73 0.34 2/57 19923 /proc/meminfo: memFree=211108/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=128156 CPUtime=3.16 /proc/19917/stat : 19917 (aptitude) S 19916 19917 17863 34816 17863 4202496 18132 2211 0 0 308 8 0 0 20 0 2 0 28201347 131231744 15747 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716610416 139848266049099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 32039 15747 5101 1052 0 12630 0 [pid=19917/tid=19922] ppid=19916 vsize=128156 CPUtime=1.97 /proc/19917/task/19922/stat : 19922 (aptitude) R 19916 19917 17863 34816 17863 4202560 7424 2211 0 0 194 3 0 0 20 0 2 0 28201378 131231744 15747 18446744073709551615 139848297304064 139848301611416 140736716618656 139848213876408 139848254807604 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.16 Current children cumulated vsize (KiB) 128156 [startup+4.00024 s] /proc/loadavg: 0.99 0.73 0.34 2/57 19923 /proc/meminfo: memFree=200320/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=134644 CPUtime=3.97 /proc/19917/stat : 19917 (aptitude) S 19916 19917 17863 34816 17863 4202496 19841 2211 0 0 388 9 0 0 20 0 2 0 28201347 137875456 17374 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716610416 139848266049099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19917/statm: 33661 17374 5102 1052 0 14252 0 [pid=19917/tid=19922] ppid=19916 vsize=134644 CPUtime=2.76 /proc/19917/task/19922/stat : 19922 (aptitude) R 19916 19917 17863 34816 17863 4202560 9133 2211 0 0 273 3 0 0 20 0 2 0 28201378 137875456 17374 18446744073709551615 139848297304064 139848301611416 140736716618656 139848213874200 139848300106031 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) 134644 [startup+4.40025 s] /proc/loadavg: 0.99 0.73 0.34 2/57 19923 /proc/meminfo: memFree=191136/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=203120 CPUtime=4.35 /proc/19917/stat : 19917 (aptitude) R 19916 19917 17863 34816 17863 4202496 21263 2211 0 0 425 10 0 0 20 0 2 0 28201347 207994880 18313 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716608744 139848292147296 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 1 0 0 /proc/19917/statm: 50780 18313 5152 1052 0 31364 0 [pid=19917/tid=19922] ppid=19916 vsize=203120 CPUtime=3.05 /proc/19917/task/19922/stat : 19922 (aptitude) S 19916 19917 17863 34816 17863 4202560 9863 2211 0 0 301 4 0 0 20 0 2 0 28201378 207994880 18313 18446744073709551615 139848297304064 139848301611416 140736716618656 139848213882880 139848266048212 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.35 Current children cumulated vsize (KiB) 203120 [startup+4.60024 s] /proc/loadavg: 0.99 0.73 0.34 2/57 19923 /proc/meminfo: memFree=191136/1022884 swapFree=0/0 [pid=19917] ppid=19916 vsize=203120 CPUtime=4.55 /proc/19917/stat : 19917 (aptitude) R 19916 19917 17863 34816 17863 4202496 29379 2714 0 0 441 13 0 1 20 0 2 0 28201347 207994880 18284 18446744073709551615 139848297304064 139848301611416 140736716618656 140736716610632 139848254795230 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 1 0 0 /proc/19917/statm: 50780 18284 5159 1052 0 31364 0 [pid=19917/tid=19922] ppid=19916 vsize=203120 CPUtime=3.06 /proc/19917/task/19922/stat : 19922 (aptitude) S 19916 19917 17863 34816 17863 4202560 9863 2714 0 0 301 4 0 1 20 0 2 0 28201378 207994880 18284 18446744073709551615 139848297304064 139848301611416 140736716618656 139848213882880 139848266048212 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.55 Current children cumulated vsize (KiB) 203120 Child status: 0 Real time (s): 4.66082 CPU time (s): 4.63229 CPU user time (s): 4.46028 CPU system time (s): 0.17201 CPU usage (%): 99.3879 Max. virtual memory (cumulated for all children) (KiB): 203120 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.46028 system time used= 0.17201 maximum resident set size= 73616 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 34563 page faults= 0 swaps= 0 block input operations= 0 block output operations= 104 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 72 involuntary context switches= 130 runsolver used 0.016001 second user time and 0.012 second system time The end