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/73.runsolver.aptitude aptitude -s -y --without-recommends install ri-db-el libsdl1.2debian ccal mtink-doc openoffice.org-l10n-th 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.99 0.71 0.32 2/55 19872 /proc/meminfo: memFree=244984/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=3152 CPUtime=0 /proc/19872/stat : 19872 (runsolver) R 19871 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28199265 3227648 32 18446744073709551615 134512640 134586868 4289530320 4289528368 4152214576 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.114858 s] /proc/loadavg: 0.99 0.71 0.32 2/55 19872 /proc/meminfo: memFree=244984/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=80316 CPUtime=0.1 /proc/19872/stat : 19872 (aptitude) R 19871 19872 17863 34816 17863 4202496 5566 1709 0 0 10 0 0 0 20 0 1 0 28199265 82243584 5366 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255566848 140401749223171 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 20079 5366 4643 1052 0 670 0 Current children cumulated CPU time (s) 0.1 Current children cumulated vsize (KiB) 80316 [startup+0.200291 s] /proc/loadavg: 0.99 0.71 0.32 2/55 19872 /proc/meminfo: memFree=244984/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=87812 CPUtime=0.19 /proc/19872/stat : 19872 (aptitude) R 19871 19872 17863 34816 17863 4202496 7733 1709 0 0 17 2 0 0 20 0 1 0 28199265 89919488 7164 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255565096 140401757306609 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 21953 7164 4721 1052 0 2544 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 87812 [startup+0.300329 s] /proc/loadavg: 0.99 0.71 0.32 2/55 19872 /proc/meminfo: memFree=244984/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=87556 CPUtime=0.29 /proc/19872/stat : 19872 (aptitude) R 19871 19872 17863 34816 17863 4202496 8629 1709 0 0 27 2 0 0 20 0 1 0 28199265 89657344 7274 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255565160 140401712263447 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 21889 7274 4725 1052 0 2480 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 87556 [startup+0.700215 s] /proc/loadavg: 0.99 0.71 0.32 2/55 19872 /proc/meminfo: memFree=244984/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=100652 CPUtime=0.69 /proc/19872/stat : 19872 (aptitude) R 19871 19872 17863 34816 17863 4202496 10133 1709 0 0 67 2 0 0 20 0 2 0 28199265 103067648 8762 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255562744 140401757089936 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 25163 8762 4994 1052 0 5754 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 100652 [startup+1.50025 s] /proc/loadavg: 0.99 0.71 0.32 2/57 19878 /proc/meminfo: memFree=229220/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=111336 CPUtime=1.47 /proc/19872/stat : 19872 (aptitude) S 19871 19872 17863 34816 17863 4202496 13919 2206 0 0 143 4 0 0 20 0 2 0 28199265 114008064 11562 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255567344 140401723127371 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 27834 11562 5099 1052 0 8425 0 [pid=19872/tid=19877] ppid=19871 vsize=111336 CPUtime=0.29 /proc/19872/task/19877/stat : 19877 (aptitude) R 19871 19872 17863 34816 17863 4202560 3224 2206 0 0 27 2 0 0 20 0 2 0 28199295 114008064 11562 18446744073709551615 140401754382336 140401758689688 140735255575584 140401670951640 140401720403368 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) 111336 [startup+3.10024 s] /proc/loadavg: 0.99 0.71 0.32 2/57 19878 /proc/meminfo: memFree=210876/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=193688 CPUtime=3.06 /proc/19872/stat : 19872 (aptitude) S 19871 19872 17863 34816 17863 4202496 18143 2206 0 0 300 6 0 0 20 0 2 0 28199265 198336512 15764 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255567344 140401723127371 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 48422 15764 5100 1052 0 29013 0 [pid=19872/tid=19877] ppid=19871 vsize=193688 CPUtime=1.88 /proc/19872/task/19877/stat : 19877 (aptitude) R 19871 19872 17863 34816 17863 4202560 7446 2206 0 0 184 4 0 0 20 0 2 0 28199295 198336512 15764 18446744073709551615 140401754382336 140401758689688 140735255575584 140401670952520 140401756593242 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) 193688 Solver just ended. Dumping a history of the last processes samples [startup+3.20032 s] /proc/loadavg: 0.99 0.71 0.32 2/57 19878 /proc/meminfo: memFree=210876/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=195012 CPUtime=3.17 /proc/19872/stat : 19872 (aptitude) S 19871 19872 17863 34816 17863 4202496 18493 2206 0 0 310 7 0 0 20 0 2 0 28199265 199692288 16084 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255567344 140401723127371 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 48753 16084 5101 1052 0 29344 0 [pid=19872/tid=19877] ppid=19871 vsize=195012 CPUtime=1.98 /proc/19872/task/19877/stat : 19877 (aptitude) R 19871 19872 17863 34816 17863 4202560 7796 2206 0 0 194 4 0 0 20 0 2 0 28199295 199692288 16084 18446744073709551615 140401754382336 140401758689688 140735255575584 140401670952472 140401757028651 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) 195012 [startup+4.00025 s] /proc/loadavg: 0.99 0.71 0.32 2/57 19878 /proc/meminfo: memFree=199716/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=201368 CPUtime=3.97 /proc/19872/stat : 19872 (aptitude) S 19871 19872 17863 34816 17863 4202496 20135 2206 0 0 390 7 0 0 20 0 2 0 28199265 206200832 17671 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255567344 140401723127371 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 50342 17671 5102 1052 0 30933 0 [pid=19872/tid=19877] ppid=19871 vsize=201368 CPUtime=2.77 /proc/19872/task/19877/stat : 19877 (aptitude) R 19871 19872 17863 34816 17863 4202560 9438 2206 0 0 273 4 0 0 20 0 2 0 28199295 206200832 17671 18446744073709551615 140401754382336 140401758689688 140735255575584 140401670954680 140401757028791 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) 201368 [startup+4.40024 s] /proc/loadavg: 0.99 0.71 0.32 2/57 19878 /proc/meminfo: memFree=190168/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=205332 CPUtime=4.36 /proc/19872/stat : 19872 (aptitude) S 19871 19872 17863 34816 17863 4202496 21146 2206 0 0 429 7 0 0 20 0 2 0 28199265 210259968 18678 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255567344 140401723127371 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 51333 18678 5103 1052 0 31924 0 [pid=19872/tid=19877] ppid=19871 vsize=205332 CPUtime=3.17 /proc/19872/task/19877/stat : 19877 (aptitude) R 19871 19872 17863 34816 17863 4202560 10449 2206 0 0 312 5 0 0 20 0 2 0 28199295 210259968 18678 18446744073709551615 140401754382336 140401758689688 140735255575584 140401670954584 140401749210156 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) 205332 [startup+4.60025 s] /proc/loadavg: 0.99 0.71 0.32 2/57 19878 /proc/meminfo: memFree=190168/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=206024 CPUtime=4.56 /proc/19872/stat : 19872 (aptitude) R 19871 19872 17863 34816 17863 4202496 22143 2206 0 0 448 8 0 0 20 0 2 0 28199265 210968576 19039 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255565416 140401749782088 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 51506 19039 5152 1052 0 32090 0 [pid=19872/tid=19877] ppid=19871 vsize=206024 CPUtime=3.21 /proc/19872/task/19877/stat : 19877 (aptitude) S 19871 19872 17863 34816 17863 4202560 10592 2206 0 0 316 5 0 0 20 0 2 0 28199295 210968576 19039 18446744073709551615 140401754382336 140401758689688 140735255575584 140401670961152 140401723126484 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) 206024 [startup+4.70024 s] /proc/loadavg: 0.99 0.71 0.32 2/57 19878 /proc/meminfo: memFree=190168/1022884 swapFree=0/0 [pid=19872] ppid=19871 vsize=206024 CPUtime=4.66 /proc/19872/stat : 19872 (aptitude) S 19871 19872 17863 34816 17863 4202496 23082 2206 0 0 457 9 0 0 20 0 2 0 28199265 210968576 19013 18446744073709551615 140401754382336 140401758689688 140735255575584 140735255565360 140401712251347 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/19872/statm: 51506 19013 5159 1052 0 32090 0 [pid=19872/tid=19877] ppid=19871 vsize=206024 CPUtime=3.21 /proc/19872/task/19877/stat : 19877 (aptitude) S 19871 19872 17863 34816 17863 4202560 10592 2206 0 0 316 5 0 0 20 0 2 0 28199295 210968576 19013 18446744073709551615 140401754382336 140401758689688 140735255575584 140401670961152 140401723126484 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.66 Current children cumulated vsize (KiB) 206024 Child status: 0 Real time (s): 4.7957 CPU time (s): 4.7763 CPU user time (s): 4.62029 CPU system time (s): 0.156009 CPU usage (%): 99.5954 Max. virtual memory (cumulated for all children) (KiB): 206024 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.62029 system time used= 0.156009 maximum resident set size= 76528 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 35985 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= 70 involuntary context switches= 135 runsolver used 0 second user time and 0.028001 second system time The end