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/122.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove klipper kenolaba libmlgtk-ocaml-dev xfonts-scalable libmlgtk-ocaml-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.00 0.99 0.91 2/55 28349 /proc/meminfo: memFree=305020/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=3152 CPUtime=0 /proc/28349/stat : 28349 (runsolver) R 28348 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28537475 3227648 33 18446744073709551615 134512640 134586868 4293054480 4293052528 4151190576 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.155613 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28349 /proc/meminfo: memFree=305020/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=34436 CPUtime=0.18 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 2063 7216 0 0 9 2 4 3 20 0 1 0 28537475 35262464 1880 18446744073709551615 4194304 5184042 140735839527168 140735839524360 140656419675671 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 8609 1880 729 242 0 1171 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 34436 [startup+0.200304 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28349 /proc/meminfo: memFree=305020/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=35360 CPUtime=0.22 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 2325 7216 0 0 13 2 4 3 20 0 1 0 28537475 36208640 2142 18446744073709551615 4194304 5184042 140735839527168 140735839524360 140656436165680 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 8840 2142 729 242 0 1402 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 35360 [startup+0.300306 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28349 /proc/meminfo: memFree=305020/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=46976 CPUtime=0.32 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 5334 7216 0 0 21 4 4 3 20 0 1 0 28537475 48103424 5143 18446744073709551615 4194304 5184042 140735839527168 140735839521656 140656420030224 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 11744 5143 835 242 0 4306 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 46976 [startup+0.700199 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28349 /proc/meminfo: memFree=305020/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=59296 CPUtime=0.72 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 8502 7216 0 0 59 6 4 3 20 0 1 0 28537475 60719104 8213 18446744073709551615 4194304 5184042 140735839527168 140735839524472 140656435988154 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 14824 8213 842 242 0 7386 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 59296 [startup+1.50021 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=274888/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=63692 CPUtime=1.52 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 9767 7216 0 0 138 7 4 3 20 0 1 0 28537475 65220608 9092 18446744073709551615 4194304 5184042 140735839527168 140735839524472 140656435924740 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 15923 9092 842 242 0 8485 0 Current children cumulated CPU time (s) 1.52 Current children cumulated vsize (KiB) 63692 [startup+3.10021 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=262488/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=77256 CPUtime=3.11 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 13432 7216 0 0 295 9 4 3 20 0 1 0 28537475 79110144 12244 18446744073709551615 4194304 5184042 140735839527168 140735839521464 140656435986834 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 19314 12244 842 242 0 11876 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 77256 [startup+6.30019 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=257652/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=81352 CPUtime=6.3 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 14981 7216 0 0 614 9 4 3 20 0 1 0 28537475 83304448 12768 18446744073709551615 4194304 5184042 140735839527168 140735839521432 140656419635821 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 20338 12768 842 242 0 12900 0 Current children cumulated CPU time (s) 6.3 Current children cumulated vsize (KiB) 81352 Solver just ended. Dumping a history of the last processes samples [startup+6.40026 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=257652/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=81352 CPUtime=6.4 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 14999 7216 0 0 624 9 4 3 20 0 1 0 28537475 83304448 12786 18446744073709551615 4194304 5184042 140735839527168 140735839521432 140656435979846 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 20338 12786 842 242 0 12900 0 Current children cumulated CPU time (s) 6.4 Current children cumulated vsize (KiB) 81352 [startup+8.00022 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=256536/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=81352 CPUtime=7.99 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 15165 7216 0 0 782 10 4 3 20 0 1 0 28537475 83304448 12952 18446744073709551615 4194304 5184042 140735839527168 140735839521464 140656435979264 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 20338 12952 842 242 0 12900 0 Current children cumulated CPU time (s) 7.99 Current children cumulated vsize (KiB) 81352 [startup+8.80022 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=256164/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=81352 CPUtime=8.79 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 15237 7216 0 0 862 10 4 3 20 0 1 0 28537475 83304448 13024 18446744073709551615 4194304 5184042 140735839527168 140735839521432 140656428448003 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 20338 13024 842 242 0 12900 0 Current children cumulated CPU time (s) 8.79 Current children cumulated vsize (KiB) 81352 [startup+9.60021 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=256164/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=81352 CPUtime=9.58 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 15310 7216 0 0 941 10 4 3 20 0 1 0 28537475 83304448 13097 18446744073709551615 4194304 5184042 140735839527168 140735839521464 140656435964661 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 20338 13097 842 242 0 12900 0 Current children cumulated CPU time (s) 9.58 Current children cumulated vsize (KiB) 81352 [startup+10.0031 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28369 /proc/meminfo: memFree=255792/1022884 swapFree=0/0 [pid=28349] ppid=28348 vsize=81352 CPUtime=9.98 /proc/28349/stat : 28349 (cupt) R 28348 28349 17872 34816 17872 4202496 15360 7216 0 0 980 11 4 3 20 0 1 0 28537475 83304448 13147 18446744073709551615 4194304 5184042 140735839527168 140735839521464 140656435995507 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28349/statm: 20338 13147 842 242 0 12900 0 Current children cumulated CPU time (s) 9.98 Current children cumulated vsize (KiB) 81352 Child status: 1 Real time (s): 10.0937 CPU time (s): 10.0846 CPU user time (s): 9.93262 CPU system time (s): 0.152009 CPU usage (%): 99.9105 Max. virtual memory (cumulated for all children) (KiB): 81352 getrusage(RUSAGE_CHILDREN,...) data: user time used= 9.93262 system time used= 0.152009 maximum resident set size= 55020 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 22610 page faults= 0 swaps= 0 block input operations= 0 block output operations= 8 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 162 runsolver used 0.016001 second user time and 0.032002 second system time The end