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/32.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install libotr1-bin archivemail cbmlink cccd libasound2-plugins 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.97 0.78 2/55 26113 /proc/meminfo: memFree=309628/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=30144 CPUtime=0 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 768 0 0 0 0 0 0 0 20 0 1 0 28321818 30867456 667 18446744073709551615 4194304 5184042 140735936664912 140735936661112 140246487071425 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 7536 667 582 242 0 98 0 [startup+0.143779 s] /proc/loadavg: 0.99 0.97 0.78 2/55 26113 /proc/meminfo: memFree=309628/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=33904 CPUtime=0.16 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 1945 7211 0 0 8 2 4 2 20 0 1 0 28321818 34717696 1764 18446744073709551615 4194304 5184042 140735936664912 140735936662104 140246467084208 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 8476 1764 729 242 0 1038 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 33904 [startup+0.200283 s] /proc/loadavg: 0.99 0.97 0.78 2/55 26113 /proc/meminfo: memFree=309628/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=35228 CPUtime=0.21 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 2281 7211 0 0 12 3 4 2 20 0 1 0 28321818 36073472 2099 18446744073709551615 4194304 5184042 140735936664912 140735936662104 140246467891626 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 8807 2099 729 242 0 1369 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35228 [startup+0.300268 s] /proc/loadavg: 0.99 0.97 0.78 2/55 26113 /proc/meminfo: memFree=309628/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=45656 CPUtime=0.31 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 4989 7211 0 0 18 7 4 2 20 0 1 0 28321818 46751744 4798 18446744073709551615 4194304 5184042 140735936664912 140735936659352 140246467150194 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 11414 4798 835 242 0 3976 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 45656 [startup+0.700204 s] /proc/loadavg: 0.99 0.97 0.78 2/55 26113 /proc/meminfo: memFree=309628/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=58616 CPUtime=0.71 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 8252 7211 0 0 57 8 4 2 20 0 1 0 28321818 60022784 7941 18446744073709551615 4194304 5184042 140735936664912 140735936661736 140246467882368 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 14654 7941 842 242 0 7216 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 58616 [startup+1.50022 s] /proc/loadavg: 0.99 0.97 0.78 2/56 26133 /proc/meminfo: memFree=279620/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=60036 CPUtime=1.51 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 8783 7211 0 0 137 8 4 2 20 0 1 0 28321818 61476864 8343 18446744073709551615 4194304 5184042 140735936664912 140735936662344 140246475962600 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 15009 8343 842 242 0 7571 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 60036 [startup+3.1002 s] /proc/loadavg: 0.99 0.97 0.78 2/56 26133 /proc/meminfo: memFree=279000/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=63108 CPUtime=3.1 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 9926 7211 0 0 296 8 4 2 20 0 1 0 28321818 64622592 8716 18446744073709551615 4194304 5184042 140735936664912 140735936662344 140246475582856 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 15777 8716 842 242 0 8339 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 63108 [startup+6.3002 s] /proc/loadavg: 0.99 0.97 0.79 2/56 26133 /proc/meminfo: memFree=270320/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=73976 CPUtime=6.29 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 13310 7211 0 0 613 10 4 2 20 0 1 0 28321818 75751424 11075 18446744073709551615 4194304 5184042 140735936664912 140735936659176 140246483494496 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 18494 11075 842 242 0 11056 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 73976 [startup+12.7002 s] /proc/loadavg: 0.99 0.97 0.79 2/56 26133 /proc/meminfo: memFree=254820/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=92912 CPUtime=12.66 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 18881 7211 0 0 1248 12 4 2 20 0 1 0 28321818 95141888 14597 18446744073709551615 4194304 5184042 140735936664912 140735936662344 140246483494432 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 23228 14597 842 242 0 15790 0 Current children cumulated CPU time (s) 12.66 Current children cumulated vsize (KiB) 92912 Solver just ended. Dumping a history of the last processes samples [startup+12.8003 s] /proc/loadavg: 0.99 0.97 0.79 2/56 26133 /proc/meminfo: memFree=254820/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=92912 CPUtime=12.76 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 18894 7211 0 0 1258 12 4 2 20 0 1 0 28321818 95141888 14610 18446744073709551615 4194304 5184042 140735936664912 140735936658328 140246483494440 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 23228 14610 842 242 0 15790 0 Current children cumulated CPU time (s) 12.76 Current children cumulated vsize (KiB) 92912 [startup+13.2002 s] /proc/loadavg: 0.99 0.97 0.79 2/56 26133 /proc/meminfo: memFree=254076/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=92912 CPUtime=13.16 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 18931 7211 0 0 1298 12 4 2 20 0 1 0 28321818 95141888 14647 18446744073709551615 4194304 5184042 140735936664912 140735936659208 140246483493888 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 23228 14647 842 242 0 15790 0 Current children cumulated CPU time (s) 13.16 Current children cumulated vsize (KiB) 92912 [startup+13.4002 s] /proc/loadavg: 0.99 0.97 0.79 2/56 26133 /proc/meminfo: memFree=254076/1022884 swapFree=0/0 [pid=26113] ppid=26112 vsize=92912 CPUtime=13.35 /proc/26113/stat : 26113 (cupt) R 26112 26113 17872 34816 17872 4202496 18957 7211 0 0 1317 12 4 2 20 0 1 0 28321818 95141888 14673 18446744073709551615 4194304 5184042 140735936664912 140735936659208 140246483510131 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26113/statm: 23228 14673 842 242 0 15790 0 Current children cumulated CPU time (s) 13.35 Current children cumulated vsize (KiB) 92912 Child status: 1 Real time (s): 13.4992 CPU time (s): 13.4728 CPU user time (s): 13.3048 CPU system time (s): 0.16801 CPU usage (%): 99.8048 Max. virtual memory (cumulated for all children) (KiB): 92912 getrusage(RUSAGE_CHILDREN,...) data: user time used= 13.3048 system time used= 0.16801 maximum resident set size= 66428 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 26199 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 221 runsolver used 0.024001 second user time and 0.040002 second system time The end