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-squeeze/logs/119.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove kfouleggs kmtrace libpcre3-dev libdb1-compat mpeglib 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.99 0.96 2/55 611 /proc/meminfo: memFree=337264/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=3152 CPUtime=0 /proc/611/stat : 611 (runsolver) R 610 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29407255 3227648 32 18446744073709551615 134512640 134586868 4289399392 4289397440 4151698480 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.149081 s] /proc/loadavg: 0.99 0.99 0.96 2/55 611 /proc/meminfo: memFree=337264/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=34168 CPUtime=0.17 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 2016 7202 0 0 8 2 5 2 20 0 1 0 29407255 34988032 1835 18446744073709551615 4194304 5184042 140734550944688 140734550941880 140031904346268 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 8542 1835 729 242 0 1104 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 34168 [startup+0.200275 s] /proc/loadavg: 0.99 0.99 0.96 2/55 611 /proc/meminfo: memFree=337264/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=35360 CPUtime=0.22 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 2318 7202 0 0 12 3 5 2 20 0 1 0 29407255 36208640 2136 18446744073709551615 4194304 5184042 140734550944688 140734550941880 140031904215384 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 8840 2136 729 242 0 1402 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 35360 [startup+0.300275 s] /proc/loadavg: 0.99 0.99 0.96 2/55 611 /proc/meminfo: memFree=337264/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=37984 CPUtime=0.32 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 3021 7202 0 0 20 5 5 2 20 0 1 0 29407255 38895616 2776 18446744073709551615 4194304 5184042 140734550944688 140734550941880 140031904626416 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 9496 2776 739 242 0 2058 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 37984 [startup+0.700223 s] /proc/loadavg: 0.99 0.99 0.96 2/55 611 /proc/meminfo: memFree=337264/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=64788 CPUtime=0.72 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 9823 7202 0 0 55 10 5 2 20 0 1 0 29407255 66342912 9570 18446744073709551615 4194304 5184042 140734550944688 140734550941928 140031904282350 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 16197 9570 851 242 0 8759 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 64788 [startup+1.50022 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=301552/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=65736 CPUtime=1.51 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 10130 7202 0 0 134 10 5 2 20 0 1 0 29407255 67313664 9812 18446744073709551615 4194304 5184042 140734550944688 140734550941992 140031920633535 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 16434 9812 851 242 0 8996 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 65736 [startup+3.10023 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=300808/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=68740 CPUtime=3.11 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 11057 7202 0 0 293 11 5 2 20 0 1 0 29407255 70389760 10353 18446744073709551615 4194304 5184042 140734550944688 140734550938936 140031920708812 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 17185 10353 851 242 0 9747 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 68740 [startup+6.30022 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=295600/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=73244 CPUtime=6.3 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 12494 7202 0 0 610 13 5 2 20 0 1 0 29407255 75001856 11277 18446744073709551615 4194304 5184042 140734550944688 140734550942120 140031920625195 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 18311 11277 851 242 0 10873 0 Current children cumulated CPU time (s) 6.3 Current children cumulated vsize (KiB) 73244 Solver just ended. Dumping a history of the last processes samples [startup+6.40029 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=295600/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=73244 CPUtime=6.4 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 12503 7202 0 0 620 13 5 2 20 0 1 0 29407255 75001856 11286 18446744073709551615 4194304 5184042 140734550944688 140734550942120 140031921489140 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 18311 11286 851 242 0 10873 0 Current children cumulated CPU time (s) 6.4 Current children cumulated vsize (KiB) 73244 [startup+8.00022 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=295104/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=73516 CPUtime=7.99 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 12723 7202 0 0 779 13 5 2 20 0 1 0 29407255 75280384 11506 18446744073709551615 4194304 5184042 140734550944688 140734550941992 140031920624640 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 18379 11506 851 242 0 10941 0 Current children cumulated CPU time (s) 7.99 Current children cumulated vsize (KiB) 73516 [startup+9.60022 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=290640/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=77228 CPUtime=9.58 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 13767 7202 0 0 938 13 5 2 20 0 1 0 29407255 79081472 12550 18446744073709551615 4194304 5184042 140734550944688 140734550938104 140031920625195 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 19307 12550 851 242 0 11869 0 Current children cumulated CPU time (s) 9.58 Current children cumulated vsize (KiB) 77228 [startup+10.4002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=290268/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=77228 CPUtime=10.38 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 13830 7202 0 0 1018 13 5 2 20 0 1 0 29407255 79081472 12613 18446744073709551615 4194304 5184042 140734550944688 140734550938104 140031913094990 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 19307 12613 851 242 0 11869 0 Current children cumulated CPU time (s) 10.38 Current children cumulated vsize (KiB) 77228 [startup+10.6002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 631 /proc/meminfo: memFree=290268/1022884 swapFree=0/0 [pid=611] ppid=610 vsize=72620 CPUtime=10.58 /proc/611/stat : 611 (cupt) R 610 611 17872 34816 17872 4202496 13847 7202 0 0 1037 14 5 2 20 0 1 0 29407255 74362880 11567 18446744073709551615 4194304 5184042 140734550944688 140734550944136 140031904271858 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/611/statm: 18155 11567 862 242 0 10717 0 Current children cumulated CPU time (s) 10.58 Current children cumulated vsize (KiB) 72620 Child status: 1 Real time (s): 10.6299 CPU time (s): 10.6167 CPU user time (s): 10.4447 CPU system time (s): 0.17201 CPU usage (%): 99.8755 Max. virtual memory (cumulated for all children) (KiB): 77228 getrusage(RUSAGE_CHILDREN,...) data: user time used= 10.4447 system time used= 0.17201 maximum resident set size= 50520 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 21069 page faults= 0 swaps= 0 block input operations= 0 block output operations= 72 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 174 runsolver used 0.012 second user time and 0.036002 second system time The end