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-sid/logs/21.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install liquidwar-data python2.3-weblib kaffe-pthreads plplot-bin python-gtk2-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.01 1.00 0.98 2/55 2809 /proc/meminfo: memFree=539132/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=3152 CPUtime=0 /proc/2809/stat : 2809 (runsolver) R 2808 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 30014604 3227648 32 18446744073709551615 134512640 134586868 4293490496 4293488544 4151194672 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.136882 s] /proc/loadavg: 1.01 1.00 0.98 2/55 2809 /proc/meminfo: memFree=539132/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=34036 CPUtime=0.16 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 1963 7197 0 0 6 3 5 2 20 0 1 0 30014604 34852864 1781 18446744073709551615 4194304 5184042 140734148820640 140734148817832 140646274305604 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 8509 1781 729 242 0 1071 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 34036 [startup+0.200264 s] /proc/loadavg: 1.01 1.00 0.98 2/55 2809 /proc/meminfo: memFree=539132/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=35492 CPUtime=0.23 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 2356 7197 0 0 12 4 5 2 20 0 1 0 30014604 36343808 2173 18446744073709551615 4194304 5184042 140734148820640 140734148817832 140646265536019 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 8873 2173 729 242 0 1435 0 Current children cumulated CPU time (s) 0.23 Current children cumulated vsize (KiB) 35492 [startup+0.300256 s] /proc/loadavg: 1.01 1.00 0.98 2/55 2809 /proc/meminfo: memFree=539132/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=38116 CPUtime=0.32 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 3056 7197 0 0 20 5 5 2 20 0 1 0 30014604 39030784 2810 18446744073709551615 4194304 5184042 140734148820640 140734148817832 140646265561166 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 9529 2810 739 242 0 2091 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 38116 [startup+0.700193 s] /proc/loadavg: 1.01 1.00 0.98 2/55 2809 /proc/meminfo: memFree=539132/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=66356 CPUtime=0.73 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 10237 7197 0 0 56 10 5 2 20 0 1 0 30014604 67948544 9982 18446744073709551615 4194304 5184042 140734148820640 140734148817944 140646281923775 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 16589 9982 851 242 0 9151 0 Current children cumulated CPU time (s) 0.73 Current children cumulated vsize (KiB) 66356 [startup+1.5002 s] /proc/loadavg: 1.01 1.00 0.98 2/56 2829 /proc/meminfo: memFree=501684/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=67976 CPUtime=1.52 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 10765 7197 0 0 135 10 5 2 20 0 1 0 30014604 69607424 10316 18446744073709551615 4194304 5184042 140734148820640 140734148817944 140646281840018 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 16994 10316 851 242 0 9556 0 Current children cumulated CPU time (s) 1.52 Current children cumulated vsize (KiB) 67976 [startup+3.10021 s] /proc/loadavg: 1.01 1.00 0.98 2/56 2829 /proc/meminfo: memFree=500320/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=69144 CPUtime=3.11 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 11390 7197 0 0 293 11 5 2 20 0 1 0 30014604 70803456 10684 18446744073709551615 4194304 5184042 140734148820640 140734148814888 140646274308611 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 17286 10684 851 242 0 9848 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 69144 [startup+6.30013 s] /proc/loadavg: 1.01 1.00 0.98 2/56 2829 /proc/meminfo: memFree=498336/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=71632 CPUtime=6.3 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 12324 7197 0 0 612 11 5 2 20 0 1 0 30014604 73351168 11105 18446744073709551615 4194304 5184042 140734148820640 140734148817944 140646281840046 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 17908 11105 851 242 0 10470 0 Current children cumulated CPU time (s) 6.3 Current children cumulated vsize (KiB) 71632 [startup+12.7002 s] /proc/loadavg: 1.01 1.00 0.98 2/56 2829 /proc/meminfo: memFree=495980/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=76280 CPUtime=12.67 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 13907 7197 0 0 1248 12 5 2 20 0 1 0 30014604 78110720 11663 18446744073709551615 4194304 5184042 140734148820640 140734148817944 140646266216452 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 19070 11663 851 242 0 11632 0 Current children cumulated CPU time (s) 12.67 Current children cumulated vsize (KiB) 76280 [startup+25.5002 s] /proc/loadavg: 1.01 1.00 0.98 2/56 2829 /proc/meminfo: memFree=491888/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=84612 CPUtime=25.42 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 16853 7197 0 0 2519 16 5 2 20 0 1 0 30014604 86642688 12560 18446744073709551615 4194304 5184042 140734148820640 140734148818072 140646281923775 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 21153 12560 851 242 0 13715 0 Current children cumulated CPU time (s) 25.42 Current children cumulated vsize (KiB) 84612 [startup+51.1002 s] /proc/loadavg: 1.00 1.00 0.98 2/56 2829 /proc/meminfo: memFree=485192/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=84612 CPUtime=50.92 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 18606 7197 0 0 5067 18 5 2 20 0 1 0 30014604 86642688 14313 18446744073709551615 4194304 5184042 140734148820640 140734148818072 140646281840171 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 21153 14313 851 242 0 13715 0 Current children cumulated CPU time (s) 50.92 Current children cumulated vsize (KiB) 84612 [startup+102.3 s] /proc/loadavg: 1.00 1.00 0.98 2/56 2829 /proc/meminfo: memFree=471056/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=101128 CPUtime=101.91 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 26178 7197 0 0 10162 22 5 2 20 0 1 0 30014604 103555072 17788 18446744073709551615 4194304 5184042 140734148820640 140734148818088 140646281840032 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 25282 17788 851 242 0 17844 0 Current children cumulated CPU time (s) 101.91 Current children cumulated vsize (KiB) 101128 [startup+162.3 s] /proc/loadavg: 1.00 1.00 0.98 2/56 3052 /proc/meminfo: memFree=455680/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=133896 CPUtime=158.54 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 38209 7197 0 0 15818 29 5 2 20 0 1 0 30014604 137109504 21626 18446744073709551615 4194304 5184042 140734148820640 140734148818072 140646281863359 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 33474 21626 851 242 0 26036 0 Current children cumulated CPU time (s) 158.54 Current children cumulated vsize (KiB) 133896 [startup+222.303 s] /proc/loadavg: 1.00 1.00 0.98 2/56 3052 /proc/meminfo: memFree=437948/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=135520 CPUtime=218.29 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 42607 7197 0 0 21790 32 5 2 20 0 1 0 30014604 138772480 26024 18446744073709551615 4194304 5184042 140734148820640 140734148817464 140646281876081 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 33880 26024 851 242 0 26442 0 Current children cumulated CPU time (s) 218.29 Current children cumulated vsize (KiB) 135520 [startup+282.3 s] /proc/loadavg: 1.00 1.00 0.98 2/56 3052 /proc/meminfo: memFree=422076/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=201056 CPUtime=278.06 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 62984 7197 0 0 27755 44 5 2 20 0 1 0 30014604 205881344 30016 18446744073709551615 4194304 5184042 140734148820640 140734148818072 140646274311569 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 50264 30016 851 242 0 42826 0 Current children cumulated CPU time (s) 278.06 Current children cumulated vsize (KiB) 201056 Maximum wall clock time exceeded: sending signal-name then SIGKILL [startup+300 s] /proc/loadavg: 1.00 1.00 0.98 2/56 3052 /proc/meminfo: memFree=417240/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=201056 CPUtime=295.69 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 64158 7197 0 0 29517 45 5 2 20 0 1 0 30014604 205881344 31190 18446744073709551615 4194304 5184042 140734148820640 140734148818072 140646281850073 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 50264 31190 851 242 0 42826 0 Current children cumulated CPU time (s) 295.69 Current children cumulated vsize (KiB) 201056 Sending Terminated to process tree (bottom up) Sleeping 2 seconds Solver just ended. Dumping a history of the last processes samples [startup+300 s] /proc/loadavg: 1.00 1.00 0.98 2/56 3052 /proc/meminfo: memFree=417240/1022884 swapFree=0/0 [pid=2809] ppid=2808 vsize=201056 CPUtime=295.69 /proc/2809/stat : 2809 (cupt) R 2808 2809 17872 34816 17872 4202496 64158 7197 0 0 29517 45 5 2 20 0 1 0 30014604 205881344 31190 18446744073709551615 4194304 5184042 140734148820640 140734148818072 140646281850073 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/2809/statm: 50264 31190 851 242 0 42826 0 Current children cumulated CPU time (s) 295.69 Current children cumulated vsize (KiB) 201056 Child ended because it received signal 15 (SIGTERM) Real time (s): 300.016 CPU time (s): 295.706 CPU user time (s): 295.222 CPU system time (s): 0.48403 CPU usage (%): 98.5637 Max. virtual memory (cumulated for all children) (KiB): 266596 getrusage(RUSAGE_CHILDREN,...) data: user time used= 295.222 system time used= 0.48403 maximum resident set size= 174760 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 71355 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= 5313 runsolver used 0 second user time and 1.20808 second system time The end