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/40.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install x-window-system-core libsub-uplevel-perl python2.2-docutils python-rpy mendexk 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.01 1.02 0.94 2/55 30859 /proc/meminfo: memFree=316076/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=3152 CPUtime=0 /proc/30859/stat : 30859 (runsolver) R 30858 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28955892 3227648 32 18446744073709551615 134512640 134586868 4290416752 4290414800 4151751728 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.158782 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30859 /proc/meminfo: memFree=316076/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=34436 CPUtime=0.17 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 2070 7210 0 0 8 3 4 2 20 0 1 0 28955892 35262464 1888 18446744073709551615 4194304 5184042 140734016306496 140734016303688 140011773168118 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 8609 1888 729 242 0 1171 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 34436 [startup+0.200275 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30859 /proc/meminfo: memFree=316076/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=35360 CPUtime=0.21 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 2312 7210 0 0 12 3 4 2 20 0 1 0 28955892 36208640 2130 18446744073709551615 4194304 5184042 140734016306496 140734016303688 140011756711426 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 8840 2130 729 242 0 1402 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35360 [startup+0.300258 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30859 /proc/meminfo: memFree=316076/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=37852 CPUtime=0.3 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 3014 7210 0 0 20 4 4 2 20 0 1 0 28955892 38760448 2769 18446744073709551615 4194304 5184042 140734016306496 140734016303688 140011756736633 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 9463 2769 739 242 0 2025 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 37852 [startup+0.700207 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30859 /proc/meminfo: memFree=316076/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=62564 CPUtime=0.7 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 9324 7210 0 0 56 8 4 2 20 0 1 0 28955892 64065536 9006 18446744073709551615 4194304 5184042 140734016306496 140734016303928 140011756671768 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 15641 9006 851 242 0 8203 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 62564 [startup+1.50021 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30879 /proc/meminfo: memFree=279248/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=67876 CPUtime=1.5 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 10841 7210 0 0 134 10 4 2 20 0 1 0 28955892 69505024 10137 18446744073709551615 4194304 5184042 140734016306496 140734016303944 140011773000390 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 16969 10137 851 242 0 9531 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 67876 [startup+3.10022 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30879 /proc/meminfo: memFree=278008/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=72528 CPUtime=3.1 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 12412 7210 0 0 293 11 4 2 20 0 1 0 28955892 74268672 11195 18446744073709551615 4194304 5184042 140734016306496 140734016303800 140011772982130 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 18132 11195 851 242 0 10694 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 72528 [startup+6.30021 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30879 /proc/meminfo: memFree=270072/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=79356 CPUtime=6.29 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 14586 7210 0 0 611 12 4 2 20 0 1 0 28955892 81260544 12344 18446744073709551615 4194304 5184042 140734016306496 140734016303800 140011773015595 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 19839 12344 851 242 0 12401 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 79356 Solver just ended. Dumping a history of the last processes samples [startup+6.40027 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30879 /proc/meminfo: memFree=270072/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=80016 CPUtime=6.39 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 14753 7210 0 0 621 12 4 2 20 0 1 0 28955892 81936384 12511 18446744073709551615 4194304 5184042 140734016306496 140734016303800 140011773022629 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 20004 12511 851 242 0 12566 0 Current children cumulated CPU time (s) 6.39 Current children cumulated vsize (KiB) 80016 [startup+6.80022 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30879 /proc/meminfo: memFree=268460/1022884 swapFree=0/0 [pid=30859] ppid=30858 vsize=73140 CPUtime=6.78 /proc/30859/stat : 30859 (cupt) R 30858 30859 17872 34816 17872 4202496 15279 7210 0 0 660 12 4 2 20 0 1 0 28955892 74895360 11708 18446744073709551615 4194304 5184042 140734016306496 140734016305944 140011756662400 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30859/statm: 18285 11708 862 242 0 10847 0 Current children cumulated CPU time (s) 6.78 Current children cumulated vsize (KiB) 73140 Child status: 1 Real time (s): 6.84445 CPU time (s): 6.84443 CPU user time (s): 6.68842 CPU system time (s): 0.156009 CPU usage (%): 99.9997 Max. virtual memory (cumulated for all children) (KiB): 81844 getrusage(RUSAGE_CHILDREN,...) data: user time used= 6.68842 system time used= 0.156009 maximum resident set size= 52876 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 22509 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= 115 runsolver used 0.012 second user time and 0.024001 second system time The end