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/38.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install gnome-pilot kernel-internals-guide libexpat1 libcoyotl2 python2.4-xmms 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 30815 /proc/meminfo: memFree=316068/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=3152 CPUtime=0 /proc/30815/stat : 30815 (runsolver) R 30814 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28955121 3227648 33 18446744073709551615 134512640 134586868 4290515344 4290513392 4152230960 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.172458 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30815 /proc/meminfo: memFree=316068/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=34700 CPUtime=0.18 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 2157 7198 0 0 10 2 4 2 20 0 1 0 28955121 35532800 1974 18446744073709551615 4194304 5184042 140735767693616 140735767690808 140705059893296 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 8675 1974 729 242 0 1237 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 34700 [startup+0.200278 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30815 /proc/meminfo: memFree=316068/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=35360 CPUtime=0.21 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 2318 7198 0 0 13 2 4 2 20 0 1 0 28955121 36208640 2135 18446744073709551615 4194304 5184042 140735767693616 140735767690808 140705060304624 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 8840 2135 729 242 0 1402 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35360 [startup+0.30026 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30815 /proc/meminfo: memFree=316068/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=37852 CPUtime=0.31 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 3021 7198 0 0 21 4 4 2 20 0 1 0 28955121 38760448 2775 18446744073709551615 4194304 5184042 140735767693616 140735767690808 140705059893448 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 9463 2775 739 242 0 2025 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 37852 [startup+0.700204 s] /proc/loadavg: 1.01 1.02 0.94 2/55 30815 /proc/meminfo: memFree=316068/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=63920 CPUtime=0.71 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 9630 7198 0 0 56 9 4 2 20 0 1 0 28955121 65454080 9376 18446744073709551615 4194304 5184042 140735767693616 140735767690872 140705076303392 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 15980 9376 851 242 0 8542 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 63920 [startup+1.5002 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30835 /proc/meminfo: memFree=281232/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=65736 CPUtime=1.51 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 10152 7198 0 0 136 9 4 2 20 0 1 0 28955121 67313664 9704 18446744073709551615 4194304 5184042 140735767693616 140735767691064 140705076277661 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 16434 9704 851 242 0 8996 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 65736 [startup+3.10022 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30835 /proc/meminfo: memFree=280116/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=66904 CPUtime=3.1 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 10613 7198 0 0 295 9 4 2 20 0 1 0 28955121 68509696 9908 18446744073709551615 4194304 5184042 140735767693616 140735767691064 140705076269923 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 16726 9908 851 242 0 9288 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 66904 Solver just ended. Dumping a history of the last processes samples [startup+3.20028 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30835 /proc/meminfo: memFree=280116/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=66904 CPUtime=3.2 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 10623 7198 0 0 305 9 4 2 20 0 1 0 28955121 68509696 9918 18446744073709551615 4194304 5184042 140735767693616 140735767691064 140705076302848 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 16726 9918 851 242 0 9288 0 Current children cumulated CPU time (s) 3.2 Current children cumulated vsize (KiB) 66904 [startup+3.6002 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30835 /proc/meminfo: memFree=279496/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=66904 CPUtime=3.6 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 10678 7198 0 0 345 9 4 2 20 0 1 0 28955121 68509696 9973 18446744073709551615 4194304 5184042 140735767693616 140735767691064 140705060669381 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 16726 9973 851 242 0 9288 0 Current children cumulated CPU time (s) 3.6 Current children cumulated vsize (KiB) 66904 [startup+3.8002 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30835 /proc/meminfo: memFree=279496/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=66904 CPUtime=3.8 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 10708 7198 0 0 365 9 4 2 20 0 1 0 28955121 68509696 10003 18446744073709551615 4194304 5184042 140735767693616 140735767687912 140705068480397 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 16726 10003 851 242 0 9288 0 Current children cumulated CPU time (s) 3.8 Current children cumulated vsize (KiB) 66904 [startup+3.90021 s] /proc/loadavg: 1.01 1.02 0.94 2/56 30835 /proc/meminfo: memFree=279496/1022884 swapFree=0/0 [pid=30815] ppid=30814 vsize=66904 CPUtime=3.9 /proc/30815/stat : 30815 (cupt) R 30814 30815 17872 34816 17872 4202496 10718 7198 0 0 375 9 4 2 20 0 1 0 28955121 68509696 10013 18446744073709551615 4194304 5184042 140735767693616 140735767687912 140705076303383 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/30815/statm: 16726 10013 851 242 0 9288 0 Current children cumulated CPU time (s) 3.9 Current children cumulated vsize (KiB) 66904 Child status: 1 Real time (s): 3.99577 CPU time (s): 4.01225 CPU user time (s): 3.89224 CPU system time (s): 0.120007 CPU usage (%): 100.413 Max. virtual memory (cumulated for all children) (KiB): 66904 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.89224 system time used= 0.120007 maximum resident set size= 40476 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 17953 page faults= 0 swaps= 0 block input operations= 0 block output operations= 40 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 76 runsolver used 0 second user time and 0.020001 second system time The end