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/92.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install libnet0-dev bnfc libgnome-ruby1.6 libstonith-dev pentanet-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: 0.92 0.98 0.99 2/55 5819 /proc/meminfo: memFree=578436/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=3152 CPUtime=0 /proc/5819/stat : 5819 (runsolver) R 5818 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 31035972 3227648 32 18446744073709551615 134512640 134586868 4292496896 4292494944 4151378992 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.132565 s] /proc/loadavg: 0.92 0.98 0.99 2/55 5819 /proc/meminfo: memFree=578436/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=33772 CPUtime=0.15 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 1913 7220 0 0 6 2 4 3 20 0 1 0 31035972 34582528 1732 18446744073709551615 4194304 5184042 140736575175408 140736575172600 140304800857149 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 8443 1732 729 242 0 1005 0 Current children cumulated CPU time (s) 0.15 Current children cumulated vsize (KiB) 33772 [startup+0.200268 s] /proc/loadavg: 0.92 0.98 0.99 2/55 5819 /proc/meminfo: memFree=578436/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=35492 CPUtime=0.22 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 2343 7220 0 0 11 4 4 3 20 0 1 0 31035972 36343808 2161 18446744073709551615 4194304 5184042 140736575175408 140736575172600 140304800857136 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 8873 2161 729 242 0 1435 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 35492 [startup+0.300258 s] /proc/loadavg: 0.92 0.98 0.99 2/55 5819 /proc/meminfo: memFree=578436/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=37984 CPUtime=0.32 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 3052 7220 0 0 19 6 4 3 20 0 1 0 31035972 38895616 2807 18446744073709551615 4194304 5184042 140736575175408 140736575172600 140304784672496 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 9496 2807 739 242 0 2058 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 37984 [startup+0.700196 s] /proc/loadavg: 0.92 0.98 0.99 2/55 5819 /proc/meminfo: memFree=578436/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=65184 CPUtime=0.72 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 9970 7220 0 0 51 14 4 3 20 0 1 0 31035972 66748416 9716 18446744073709551615 4194304 5184042 140736575175408 140736575172232 140304793136107 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 16296 9716 851 242 0 8858 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 65184 [startup+1.5002 s] /proc/loadavg: 0.92 0.98 0.99 2/56 5839 /proc/meminfo: memFree=541476/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=66756 CPUtime=1.51 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 10503 7220 0 0 130 14 4 3 20 0 1 0 31035972 68358144 10055 18446744073709551615 4194304 5184042 140736575175408 140736575169704 140304784322384 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 16689 10055 851 242 0 9251 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 66756 [startup+3.1002 s] /proc/loadavg: 0.92 0.98 0.99 2/56 5839 /proc/meminfo: memFree=540856/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=67780 CPUtime=3.11 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 10898 7220 0 0 290 14 4 3 20 0 1 0 31035972 69406720 10193 18446744073709551615 4194304 5184042 140736575175408 140736575172840 140304800670720 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 16945 10193 851 242 0 9507 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 67780 [startup+6.30019 s] /proc/loadavg: 0.93 0.98 0.99 2/56 5839 /proc/meminfo: memFree=539492/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=70124 CPUtime=6.3 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 11796 7220 0 0 608 15 4 3 20 0 1 0 31035972 71806976 10578 18446744073709551615 4194304 5184042 140736575175408 140736575172840 140304800671240 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 17531 10578 851 242 0 10093 0 Current children cumulated CPU time (s) 6.3 Current children cumulated vsize (KiB) 70124 [startup+12.7002 s] /proc/loadavg: 0.93 0.98 0.99 2/56 5839 /proc/meminfo: memFree=537136/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=74516 CPUtime=12.67 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 13430 7220 0 0 1243 17 4 3 20 0 1 0 31035972 76304384 11187 18446744073709551615 4194304 5184042 140736575175408 140736575172712 140304800677944 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 18629 11187 851 242 0 11191 0 Current children cumulated CPU time (s) 12.67 Current children cumulated vsize (KiB) 74516 [startup+25.5001 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=531308/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=83884 CPUtime=25.42 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 16889 7220 0 0 2516 19 4 3 20 0 1 0 31035972 85897216 12597 18446744073709551615 4194304 5184042 140736575175408 140736575172712 140304800671807 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 20971 12597 851 242 0 13533 0 Current children cumulated CPU time (s) 25.42 Current children cumulated vsize (KiB) 83884 Solver just ended. Dumping a history of the last processes samples [startup+25.6002 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=531308/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=83884 CPUtime=25.52 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 16898 7220 0 0 2526 19 4 3 20 0 1 0 31035972 85897216 12606 18446744073709551615 4194304 5184042 140736575175408 140736575172712 140304792752581 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 20971 12606 851 242 0 13533 0 Current children cumulated CPU time (s) 25.52 Current children cumulated vsize (KiB) 83884 [startup+32.0031 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=528952/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=83884 CPUtime=31.89 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 17482 7220 0 0 3163 19 4 3 20 0 1 0 31035972 85897216 13190 18446744073709551615 4194304 5184042 140736575175408 140736575172712 140304792759688 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 20971 13190 851 242 0 13533 0 Current children cumulated CPU time (s) 31.89 Current children cumulated vsize (KiB) 83884 [startup+35.2002 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=527712/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=84032 CPUtime=35.08 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 17780 7220 0 0 3482 19 4 3 20 0 1 0 31035972 86048768 13488 18446744073709551615 4194304 5184042 140736575175408 140736575172712 140304792752606 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 21008 13488 851 242 0 13570 0 Current children cumulated CPU time (s) 35.08 Current children cumulated vsize (KiB) 84032 [startup+36.8002 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=527340/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=84032 CPUtime=36.67 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 17935 7220 0 0 3641 19 4 3 20 0 1 0 31035972 86048768 13643 18446744073709551615 4194304 5184042 140736575175408 140736575172712 140304800686953 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 21008 13643 851 242 0 13570 0 Current children cumulated CPU time (s) 36.67 Current children cumulated vsize (KiB) 84032 [startup+37.2002 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=527340/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=84032 CPUtime=37.07 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 18027 7220 0 0 3681 19 4 3 20 0 1 0 31035972 86048768 13735 18446744073709551615 4194304 5184042 140736575175408 140736575172712 140304792761645 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 21008 13735 851 242 0 13570 0 Current children cumulated CPU time (s) 37.07 Current children cumulated vsize (KiB) 84032 [startup+37.6002 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=526472/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=84032 CPUtime=37.47 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 18084 7220 0 0 3721 19 4 3 20 0 1 0 31035972 86048768 13792 18446744073709551615 4194304 5184042 140736575175408 140736575169704 140304800671112 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 21008 13792 851 242 0 13570 0 Current children cumulated CPU time (s) 37.47 Current children cumulated vsize (KiB) 84032 [startup+37.7002 s] /proc/loadavg: 0.95 0.98 0.99 2/56 5839 /proc/meminfo: memFree=526472/1022884 swapFree=0/0 [pid=5819] ppid=5818 vsize=67132 CPUtime=37.57 /proc/5819/stat : 5819 (cupt) R 5818 5819 17872 34816 17872 4202496 18103 7220 0 0 3731 19 4 3 20 0 1 0 31035972 68743168 10199 18446744073709551615 4194304 5184042 140736575175408 140736575174856 140304801316001 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/5819/statm: 16783 10199 862 242 0 9345 0 Current children cumulated CPU time (s) 37.57 Current children cumulated vsize (KiB) 67132 Child status: 1 Real time (s): 37.7499 CPU time (s): 37.6264 CPU user time (s): 37.3903 CPU system time (s): 0.236014 CPU usage (%): 99.6728 Max. virtual memory (cumulated for all children) (KiB): 84032 getrusage(RUSAGE_CHILDREN,...) data: user time used= 37.3903 system time used= 0.236014 maximum resident set size= 57432 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 25343 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= 583 runsolver used 0 second user time and 0.16001 second system time The end