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/85.runsolver.aptitude aptitude -s -y --without-recommends install po-debiandoc kreversi decompyle libiw27 libneon24-dev 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.02 1.07 1.02 2/55 22061 /proc/meminfo: memFree=850096/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=3152 CPUtime=0 /proc/22061/stat : 22061 (runsolver) R 22060 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28596331 3227648 33 18446744073709551615 134512640 134586868 4293416192 4293414240 4151395376 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.19006 s] /proc/loadavg: 1.02 1.07 1.02 2/55 22061 /proc/meminfo: memFree=850096/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=89152 CPUtime=0.17 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 7777 1708 0 0 17 0 0 0 20 0 1 0 28596331 91291648 7576 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323200 140524229393168 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 22288 7576 6665 1052 0 858 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 89152 [startup+0.20029 s] /proc/loadavg: 1.02 1.07 1.02 2/55 22061 /proc/meminfo: memFree=850096/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=89152 CPUtime=0.18 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 7871 1708 0 0 17 1 0 0 20 0 1 0 28596331 91291648 7662 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982321712 140524229564386 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 22288 7662 6726 1052 0 858 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 89152 [startup+0.300276 s] /proc/loadavg: 1.02 1.07 1.02 2/55 22061 /proc/meminfo: memFree=850096/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=101864 CPUtime=0.28 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 11707 1708 0 0 26 2 0 0 20 0 1 0 28596331 104308736 10753 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982321368 140524229611398 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 25466 10753 6743 1052 0 4036 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 101864 [startup+0.700208 s] /proc/loadavg: 1.02 1.07 1.02 2/55 22061 /proc/meminfo: memFree=850096/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=114208 CPUtime=0.69 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 13729 1708 0 0 66 3 0 0 20 0 2 0 28596331 116948992 12101 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323208 140524229535192 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 28552 12101 6977 1052 0 7122 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 114208 [startup+1.50023 s] /proc/loadavg: 1.02 1.07 1.02 2/57 22066 /proc/meminfo: memFree=829256/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=115376 CPUtime=1.47 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 14604 2206 0 0 143 4 0 0 20 0 2 0 28596331 118145024 12351 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323960 140524201023501 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 28844 12351 7073 1052 0 7414 0 [pid=22061/tid=22066] ppid=22060 vsize=115376 CPUtime=0 /proc/22061/task/22066/stat : 22066 (aptitude) S 22060 22061 17863 34816 17863 4202560 6 2206 0 0 0 0 0 0 20 0 2 0 28596376 118145024 12351 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138117120 140524203455188 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) 115376 [startup+3.10024 s] /proc/loadavg: 1.02 1.07 1.02 2/57 22067 /proc/meminfo: memFree=821816/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=197808 CPUtime=3.07 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 19417 2206 0 0 300 7 0 0 20 0 2 0 28596331 202555392 16798 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 49452 16798 7128 1052 0 28022 0 [pid=22061/tid=22066] ppid=22060 vsize=197808 CPUtime=1.08 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 4790 2206 0 0 106 2 0 0 20 0 2 0 28596376 202555392 16798 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138110776 140524192221511 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) 197808 [startup+6.30025 s] /proc/loadavg: 1.02 1.07 1.02 2/57 22067 /proc/meminfo: memFree=788956/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=226800 CPUtime=6.26 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 26985 2206 0 0 616 10 0 0 20 0 2 0 28596331 232243200 24039 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 56700 24039 7129 1052 0 35270 0 [pid=22061/tid=22066] ppid=22060 vsize=226800 CPUtime=4.26 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 12358 2206 0 0 421 5 0 0 20 0 2 0 28596376 232243200 24039 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138110648 140524237308101 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.26 Current children cumulated vsize (KiB) 226800 [startup+12.7002 s] /proc/loadavg: 1.02 1.07 1.02 2/57 22067 /proc/meminfo: memFree=736752/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=276648 CPUtime=12.62 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 39442 2206 0 0 1247 15 0 0 20 0 2 0 28596331 283287552 36488 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 69162 36488 7129 1052 0 47732 0 [pid=22061/tid=22066] ppid=22060 vsize=276648 CPUtime=10.63 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 24815 2206 0 0 1053 10 0 0 20 0 2 0 28596376 283287552 36488 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138108440 140524192211364 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.62 Current children cumulated vsize (KiB) 276648 [startup+25.5003 s] /proc/loadavg: 1.01 1.07 1.02 2/57 22067 /proc/meminfo: memFree=631972/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=378436 CPUtime=25.37 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 64866 2206 0 0 2511 26 0 0 20 0 2 0 28596331 387518464 61897 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 94609 61897 7129 1052 0 73179 0 [pid=22061/tid=22066] ppid=22060 vsize=378436 CPUtime=23.37 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 50239 2206 0 0 2316 21 0 0 20 0 2 0 28596376 387518464 61897 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138110648 140524237344307 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 25.37 Current children cumulated vsize (KiB) 378436 [startup+51.1003 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22067 /proc/meminfo: memFree=474864/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=536032 CPUtime=50.85 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 104479 2206 0 0 5042 43 0 0 20 0 2 0 28596331 548896768 101272 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 134008 101272 7143 1052 0 112578 0 [pid=22061/tid=22066] ppid=22060 vsize=536032 CPUtime=48.85 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 89845 2206 0 0 4847 38 0 0 20 0 2 0 28596376 548896768 101272 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138110696 140524235356466 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 50.85 Current children cumulated vsize (KiB) 536032 Solver just ended. Dumping a history of the last processes samples [startup+51.2003 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22067 /proc/meminfo: memFree=474864/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=536428 CPUtime=50.95 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 104571 2206 0 0 5052 43 0 0 20 0 2 0 28596331 549302272 101364 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 134107 101364 7143 1052 0 112677 0 [pid=22061/tid=22066] ppid=22060 vsize=536428 CPUtime=48.95 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 89937 2206 0 0 4857 38 0 0 20 0 2 0 28596376 549302272 101364 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138108440 140524201020395 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 50.95 Current children cumulated vsize (KiB) 536428 [startup+54.4002 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22067 /proc/meminfo: memFree=459240/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=551644 CPUtime=54.13 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 108380 2206 0 0 5369 44 0 0 20 0 2 0 28596331 564883456 105167 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 137911 105167 7143 1052 0 116481 0 [pid=22061/tid=22066] ppid=22060 vsize=551644 CPUtime=52.15 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 93746 2206 0 0 5175 40 0 0 20 0 2 0 28596376 564883456 105167 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138110648 140524237539932 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 54.13 Current children cumulated vsize (KiB) 551644 [startup+56.0002 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22067 /proc/meminfo: memFree=454776/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=558132 CPUtime=55.72 /proc/22061/stat : 22061 (aptitude) S 22060 22061 17863 34816 17863 4202496 110010 2206 0 0 5527 45 0 0 20 0 2 0 28596331 571527168 106797 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982323696 140524203456075 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 139533 106797 7143 1052 0 118103 0 [pid=22061/tid=22066] ppid=22060 vsize=558132 CPUtime=53.73 /proc/22061/task/22066/stat : 22066 (aptitude) R 22060 22061 17863 34816 17863 4202560 95376 2206 0 0 5333 40 0 0 20 0 2 0 28596376 571527168 106797 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138110648 140524237418357 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 55.72 Current children cumulated vsize (KiB) 558132 [startup+57.6003 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22067 /proc/meminfo: memFree=444856/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=562484 CPUtime=57.32 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 111446 2206 0 0 5686 46 0 0 20 0 2 0 28596331 575983616 108106 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982322072 140524192202322 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 140621 108106 7191 1052 0 119184 0 [pid=22061/tid=22066] ppid=22060 vsize=562484 CPUtime=54.62 /proc/22061/task/22066/stat : 22066 (aptitude) S 22060 22061 17863 34816 17863 4202560 96434 2206 0 0 5421 41 0 0 20 0 2 0 28596376 575983616 108106 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138117120 140524203455188 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 57.32 Current children cumulated vsize (KiB) 562484 [startup+58.0002 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22067 /proc/meminfo: memFree=444856/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=562484 CPUtime=57.71 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 111943 2206 0 0 5725 46 0 0 20 0 2 0 28596331 575983616 108107 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982322024 140524230111104 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 140621 108107 7192 1052 0 119184 0 [pid=22061/tid=22066] ppid=22060 vsize=562484 CPUtime=54.62 /proc/22061/task/22066/stat : 22066 (aptitude) S 22060 22061 17863 34816 17863 4202560 96434 2206 0 0 5421 41 0 0 20 0 2 0 28596376 575983616 108107 18446744073709551615 140524234711040 140524239018392 140735982331936 140524138117120 140524203455188 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 57.71 Current children cumulated vsize (KiB) 562484 [startup+58.4033 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22067 /proc/meminfo: memFree=444104/1022884 swapFree=0/0 [pid=22061] ppid=22060 vsize=366100 CPUtime=58.13 /proc/22061/stat : 22061 (aptitude) R 22060 22061 17863 34816 17863 4202496 114206 2707 0 0 5749 62 0 2 20 0 1 0 28596331 374886400 56954 18446744073709551615 140524234711040 140524239018392 140735982331936 140735982331496 140524192577002 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22061/statm: 91525 56954 1521 1052 0 75781 0 Current children cumulated CPU time (s) 58.13 Current children cumulated vsize (KiB) 366100 Child status: 0 Real time (s): 58.4591 CPU time (s): 58.1996 CPU user time (s): 57.5036 CPU system time (s): 0.696043 CPU usage (%): 99.5561 Max. virtual memory (cumulated for all children) (KiB): 562484 getrusage(RUSAGE_CHILDREN,...) data: user time used= 57.5036 system time used= 0.696043 maximum resident set size= 432760 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 116980 page faults= 0 swaps= 0 block input operations= 0 block output operations= 144 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 171 involuntary context switches= 1025 runsolver used 0.088005 second user time and 0.180011 second system time The end