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/12.runsolver.aptitude aptitude -s -y --without-recommends install titrax mozilla-locale-ko python2.2-egenix-mxstack libuuid1 websec 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.50 1.12 0.82 2/55 20921 /proc/meminfo: memFree=978736/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=3152 CPUtime=0 /proc/20921/stat : 20921 (runsolver) R 20920 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28314090 3227648 32 18446744073709551615 134512640 134586868 4293877728 4293875776 4151407664 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/20921/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.168378 s] /proc/loadavg: 1.50 1.12 0.82 2/55 20921 /proc/meminfo: memFree=978736/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=48572 CPUtime=0 /proc/20921/stat : 20921 (aptitude) D 20920 20921 17863 34816 17863 4202496 198 0 12 0 0 0 0 0 20 0 1 0 28314090 49737728 115 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377343096 140590835016247 0 0 0 0 0 0 0 17 0 0 0 15 0 0 /proc/20921/statm: 12143 115 69 1052 0 66 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 48572 [startup+0.200291 s] /proc/loadavg: 1.50 1.12 0.82 2/55 20921 /proc/meminfo: memFree=978736/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=54860 CPUtime=0 /proc/20921/stat : 20921 (aptitude) D 20920 20921 17863 34816 17863 4202496 445 0 21 0 0 0 0 0 20 0 1 0 28314090 56176640 366 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377345848 140590834971624 0 0 0 0 0 0 0 17 0 0 0 18 0 0 /proc/20921/statm: 13715 366 284 1052 0 73 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 54860 [startup+0.300382 s] /proc/loadavg: 1.50 1.12 0.82 2/55 20921 /proc/meminfo: memFree=978736/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=54968 CPUtime=0.01 /proc/20921/stat : 20921 (aptitude) D 20920 20921 17863 34816 17863 4202496 866 0 36 0 0 1 0 0 20 0 1 0 28314090 56287232 794 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377346352 140590831997920 0 0 0 0 0 0 0 17 0 0 0 28 0 0 /proc/20921/statm: 13742 794 653 1052 0 106 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 54968 [startup+0.700321 s] /proc/loadavg: 1.50 1.12 0.82 2/55 20921 /proc/meminfo: memFree=978736/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=63384 CPUtime=0.01 /proc/20921/stat : 20921 (aptitude) S 20920 20921 17863 34816 17863 4202496 1174 0 68 0 0 1 0 0 20 0 1 0 28314090 64905216 1108 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377337688 140590795007728 0 134217728 4096 0 0 0 0 17 0 0 0 62 0 0 /proc/20921/statm: 15846 1108 929 1052 0 109 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 63384 [startup+1.50035 s] /proc/loadavg: 1.46 1.12 0.82 2/56 20925 /proc/meminfo: memFree=967196/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=89152 CPUtime=0.03 /proc/20921/stat : 20921 (aptitude) D 20920 20921 17863 34816 17863 4202496 2698 1705 213 4 0 3 0 0 20 0 1 0 28314090 91291648 2711 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377338112 140590832211866 0 134217728 4096 0 0 0 0 17 0 0 0 138 0 0 /proc/20921/statm: 22288 2711 1800 1052 0 858 0 Current children cumulated CPU time (s) 0.03 Current children cumulated vsize (KiB) 89152 [startup+3.10023 s] /proc/loadavg: 1.46 1.12 0.82 2/56 20925 /proc/meminfo: memFree=934956/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=114208 CPUtime=0.95 /proc/20921/stat : 20921 (aptitude) R 20920 20921 17863 34816 17863 4202496 13507 1705 273 4 83 12 0 0 20 0 2 0 28314090 116948992 12151 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377336936 140590837807410 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 206 0 0 /proc/20921/statm: 28552 12151 7014 1052 0 7122 0 Current children cumulated CPU time (s) 0.95 Current children cumulated vsize (KiB) 114208 heavy processes: [startup+6.30025 s] /proc/loadavg: 1.42 1.12 0.82 2/57 20927 /proc/meminfo: memFree=852364/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=157188 CPUtime=4.09 /proc/20921/stat : 20921 (aptitude) S 20920 20921 17863 34816 17863 4202496 25979 2204 275 4 392 16 1 0 20 0 2 0 28314090 160960512 22998 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377338400 140590805907019 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 207 0 0 /proc/20921/statm: 39297 22998 7122 1052 0 17867 0 [pid=20921/tid=20926] ppid=20920 vsize=157188 CPUtime=2.18 /proc/20921/task/20926/stat : 20926 (aptitude) R 20920 20921 17863 34816 17863 4202560 11723 2204 1 4 215 2 1 0 20 0 2 0 28314347 160960512 22998 18446744073709551615 140590837161984 140590841469336 140734377346640 140590740561672 140590794657582 0 134217728 4096 0 0 0 0 -1 0 0 0 4 0 0 Current children cumulated CPU time (s) 4.09 Current children cumulated vsize (KiB) 157188 heavy processes: Solver just ended. Dumping a history of the last processes samples [startup+6.40337 s] /proc/loadavg: 1.42 1.12 0.82 2/57 20927 /proc/meminfo: memFree=844304/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=157716 CPUtime=4.19 /proc/20921/stat : 20921 (aptitude) S 20920 20921 17863 34816 17863 4202496 26129 2204 275 4 402 16 1 0 20 0 2 0 28314090 161501184 23148 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377338400 140590805907019 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 207 0 0 /proc/20921/statm: 39429 23148 7122 1052 0 17999 0 [pid=20921/tid=20926] ppid=20920 vsize=157716 CPUtime=2.28 /proc/20921/task/20926/stat : 20926 (aptitude) R 20920 20921 17863 34816 17863 4202560 11873 2204 1 4 225 2 1 0 20 0 2 0 28314347 161501184 23148 18446744073709551615 140590837161984 140590841469336 140734377346640 140590740561672 140590839758695 0 134217728 4096 0 0 0 0 -1 0 0 0 4 0 0 Current children cumulated CPU time (s) 4.19 Current children cumulated vsize (KiB) 157716 [startup+8.00025 s] /proc/loadavg: 1.42 1.12 0.82 2/57 20927 /proc/meminfo: memFree=829300/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=240596 CPUtime=5.78 /proc/20921/stat : 20921 (aptitude) S 20920 20921 17863 34816 17863 4202496 30467 2204 275 4 559 18 1 0 20 0 2 0 28314090 246370304 27485 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377338400 140590805907019 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 207 0 0 /proc/20921/statm: 60149 27485 7122 1052 0 38719 0 [pid=20921/tid=20926] ppid=20920 vsize=240596 CPUtime=3.87 /proc/20921/task/20926/stat : 20926 (aptitude) R 20920 20921 17863 34816 17863 4202560 16210 2204 1 4 382 4 1 0 20 0 2 0 28314347 246370304 27485 18446744073709551615 140590837161984 140590841469336 140734377346640 140590740561720 140590839795163 0 134217728 4096 0 0 0 0 -1 0 0 0 4 0 0 Current children cumulated CPU time (s) 5.78 Current children cumulated vsize (KiB) 240596 [startup+8.80025 s] /proc/loadavg: 1.42 1.12 0.82 2/57 20927 /proc/meminfo: memFree=816900/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=249976 CPUtime=6.56 /proc/20921/stat : 20921 (aptitude) S 20920 20921 17863 34816 17863 4202496 32842 2204 276 4 636 19 1 0 20 0 2 0 28314090 255975424 29832 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377338400 140590805907019 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 207 0 0 /proc/20921/statm: 62494 29832 7123 1052 0 41064 0 [pid=20921/tid=20926] ppid=20920 vsize=249976 CPUtime=4.65 /proc/20921/task/20926/stat : 20926 (aptitude) R 20920 20921 17863 34816 17863 4202560 18585 2204 2 4 459 5 1 0 20 0 2 0 28314347 255975424 29832 18446744073709551615 140590837161984 140590841469336 140734377346640 140590740559416 140590840053139 0 134217728 4096 0 0 0 0 -1 0 0 0 5 0 0 Current children cumulated CPU time (s) 6.56 Current children cumulated vsize (KiB) 249976 [startup+9.60026 s] /proc/loadavg: 1.42 1.12 0.82 2/57 20927 /proc/meminfo: memFree=816900/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=255932 CPUtime=7.31 /proc/20921/stat : 20921 (aptitude) R 20920 20921 17863 34816 17863 4202496 34374 2204 282 4 710 20 1 0 20 0 2 0 28314090 262074368 31361 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377336936 140590794653355 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 213 0 0 /proc/20921/statm: 63983 31361 7172 1052 0 42546 0 [pid=20921/tid=20926] ppid=20920 vsize=255932 CPUtime=5.27 /proc/20921/task/20926/stat : 20926 (aptitude) S 20920 20921 17863 34816 17863 4202560 20021 2204 2 4 520 6 1 0 20 0 2 0 28314347 262074368 31361 18446744073709551615 140590837161984 140590841469336 140734377346640 140590740568064 140590805906132 0 134217728 4096 0 0 0 0 -1 0 0 0 5 0 0 Current children cumulated CPU time (s) 7.31 Current children cumulated vsize (KiB) 255932 [startup+9.80025 s] /proc/loadavg: 1.42 1.12 0.82 2/57 20927 /proc/meminfo: memFree=816900/1022884 swapFree=0/0 [pid=20921] ppid=20920 vsize=255932 CPUtime=7.5 /proc/20921/stat : 20921 (aptitude) R 20920 20921 17863 34816 17863 4202496 36197 2204 282 4 729 20 1 0 20 0 2 0 28314090 262074368 31442 18446744073709551615 140590837161984 140590841469336 140734377346640 140734377338344 140590794743488 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 213 0 0 /proc/20921/statm: 63983 31442 7173 1052 0 42546 0 [pid=20921/tid=20926] ppid=20920 vsize=255932 CPUtime=5.27 /proc/20921/task/20926/stat : 20926 (aptitude) S 20920 20921 17863 34816 17863 4202560 20021 2204 2 4 520 6 1 0 20 0 2 0 28314347 262074368 31442 18446744073709551615 140590837161984 140590841469336 140734377346640 140590740568064 140590805906132 0 134217728 4096 0 0 0 0 -1 0 0 0 5 0 0 Current children cumulated CPU time (s) 7.5 Current children cumulated vsize (KiB) 255932 Child status: 0 Real time (s): 9.89059 CPU time (s): 7.60448 CPU user time (s): 7.32846 CPU system time (s): 0.276017 CPU usage (%): 76.886 Max. virtual memory (cumulated for all children) (KiB): 255932 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.32846 system time used= 0.276017 maximum resident set size= 125788 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 39157 page faults= 289 swaps= 0 block input operations= 142016 block output operations= 8 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 1538 involuntary context switches= 189 runsolver used 0.012 second user time and 0.048003 second system time The end