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/11.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install vcheck libsp-gxmlcpp1 ldapvi python-pyxine nwall 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.97 0.89 0.53 2/55 25641 /proc/meminfo: memFree=256516/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=3152 CPUtime=0 /proc/25641/stat : 25641 (runsolver) R 25640 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28233186 3227648 33 18446744073709551615 134512640 134586868 4290032752 4290030800 4152038448 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.117102 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25641 /proc/meminfo: memFree=256516/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=33244 CPUtime=0.13 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 1767 7191 0 0 5 2 4 2 20 0 1 0 28233186 34041856 1585 18446744073709551615 4194304 5184042 140736247279600 140736247276792 140519844225113 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 8311 1585 729 242 0 873 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 33244 [startup+0.20028 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25641 /proc/meminfo: memFree=256516/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=35228 CPUtime=0.21 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 2292 7191 0 0 12 3 4 2 20 0 1 0 28233186 36073472 2109 18446744073709551615 4194304 5184042 140736247279600 140736247276792 140519844199938 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 8807 2109 729 242 0 1369 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35228 [startup+0.300272 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25641 /proc/meminfo: memFree=256516/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=46056 CPUtime=0.31 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 5107 7191 0 0 21 4 4 2 20 0 1 0 28233186 47161344 4916 18446744073709551615 4194304 5184042 140736247279600 140736247274040 140519861150164 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 11514 4916 835 242 0 4076 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 46056 [startup+0.700215 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25641 /proc/meminfo: memFree=256516/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=57344 CPUtime=0.71 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 7979 7191 0 0 60 5 4 2 20 0 1 0 28233186 58720256 7727 18446744073709551615 4194304 5184042 140736247279600 140736247276904 140519860539715 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 14336 7727 842 242 0 6898 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 57344 [startup+1.5002 s] /proc/loadavg: 0.97 0.89 0.53 2/56 25661 /proc/meminfo: memFree=228492/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=58524 CPUtime=1.51 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 8405 7191 0 0 139 6 4 2 20 0 1 0 28233186 59928576 7959 18446744073709551615 4194304 5184042 140736247279600 140736247276904 140519860503995 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 14631 7959 842 242 0 7193 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 58524 [startup+3.10022 s] /proc/loadavg: 0.97 0.89 0.53 2/56 25661 /proc/meminfo: memFree=227128/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=59548 CPUtime=3.1 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 8909 7191 0 0 298 6 4 2 20 0 1 0 28233186 60977152 8206 18446744073709551615 4194304 5184042 140736247279600 140736247277032 140519852592556 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 14887 8206 842 242 0 7449 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 59548 [startup+6.3002 s] /proc/loadavg: 0.97 0.89 0.53 2/56 25661 /proc/meminfo: memFree=225640/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=61596 CPUtime=6.28 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 9910 7191 0 0 616 6 4 2 20 0 1 0 28233186 63074304 8694 18446744073709551615 4194304 5184042 140736247279600 140736247277032 140519860503954 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 15399 8694 842 242 0 7961 0 Current children cumulated CPU time (s) 6.28 Current children cumulated vsize (KiB) 61596 [startup+12.7002 s] /proc/loadavg: 0.97 0.89 0.53 2/56 25661 /proc/meminfo: memFree=207164/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=79376 CPUtime=12.66 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 15455 7191 0 0 1252 8 4 2 20 0 1 0 28233186 81281024 13214 18446744073709551615 4194304 5184042 140736247279600 140736247273896 140519844160193 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 19844 13214 842 242 0 12406 0 Current children cumulated CPU time (s) 12.66 Current children cumulated vsize (KiB) 79376 Solver just ended. Dumping a history of the last processes samples [startup+12.8003 s] /proc/loadavg: 0.97 0.89 0.53 2/56 25661 /proc/meminfo: memFree=207164/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=79376 CPUtime=12.75 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 15468 7191 0 0 1261 8 4 2 20 0 1 0 28233186 81281024 13227 18446744073709551615 4194304 5184042 140736247279600 140736247273896 140519852681324 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 19844 13227 842 242 0 12406 0 Current children cumulated CPU time (s) 12.75 Current children cumulated vsize (KiB) 79376 [startup+13.0002 s] /proc/loadavg: 0.97 0.89 0.53 2/56 25661 /proc/meminfo: memFree=207164/1022884 swapFree=0/0 [pid=25641] ppid=25640 vsize=71164 CPUtime=12.96 /proc/25641/stat : 25641 (cupt) R 25640 25641 17872 34816 17872 4202496 15500 7191 0 0 1281 9 4 2 20 0 1 0 28233186 72871936 11211 18446744073709551615 4194304 5184042 140736247279600 140736247278760 140519844155216 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25641/statm: 17791 11211 853 242 0 10353 0 Current children cumulated CPU time (s) 12.96 Current children cumulated vsize (KiB) 71164 Child status: 1 Real time (s): 13.0558 CPU time (s): 13.0328 CPU user time (s): 12.9048 CPU system time (s): 0.128008 CPU usage (%): 99.8237 Max. virtual memory (cumulated for all children) (KiB): 79376 getrusage(RUSAGE_CHILDREN,...) data: user time used= 12.9048 system time used= 0.128008 maximum resident set size= 53036 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 22711 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= 213 runsolver used 0.016001 second user time and 0.044002 second system time The end