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/156.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove cpio libasound2 ncurses-base libgpgme11 libgcrypt11-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 Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 0.92 0.97 0.91 2/55 29330 /proc/meminfo: memFree=311568/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=30148 CPUtime=0 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 788 0 0 0 0 0 0 0 20 0 1 0 28668880 30871552 687 18446744073709551615 4194304 5184042 140737220121488 140737220119496 140667541762544 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 7537 687 595 242 0 99 0 [startup+0.171597 s] /proc/loadavg: 0.92 0.97 0.91 2/55 29330 /proc/meminfo: memFree=311568/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=34700 CPUtime=0.19 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 2155 7196 0 0 11 1 4 3 20 0 1 0 28668880 35532800 1973 18446744073709551615 4194304 5184042 140737220121488 140737220118680 140667525525015 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 8675 1973 729 242 0 1237 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 34700 [startup+0.200269 s] /proc/loadavg: 0.92 0.97 0.91 2/55 29330 /proc/meminfo: memFree=311568/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=35360 CPUtime=0.22 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 2325 7196 0 0 14 1 4 3 20 0 1 0 28668880 36208640 2143 18446744073709551615 4194304 5184042 140737220121488 140737220118680 140667525418936 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 8840 2143 729 242 0 1402 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 35360 [startup+0.300258 s] /proc/loadavg: 0.92 0.97 0.91 2/55 29330 /proc/meminfo: memFree=311568/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=46976 CPUtime=0.32 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 5341 7196 0 0 20 5 4 3 20 0 1 0 28668880 48103424 5150 18446744073709551615 4194304 5184042 140737220121488 140737220115976 140667541885505 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 11744 5150 835 242 0 4306 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 46976 [startup+0.700198 s] /proc/loadavg: 0.92 0.97 0.91 2/55 29330 /proc/meminfo: memFree=311568/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=59128 CPUtime=0.72 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 8383 7196 0 0 58 7 4 3 20 0 1 0 28668880 60547072 8094 18446744073709551615 4194304 5184042 140737220121488 140737220118920 140667541828608 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 14782 8094 842 242 0 7344 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 59128 [startup+1.50021 s] /proc/loadavg: 0.93 0.97 0.91 2/56 29350 /proc/meminfo: memFree=280692/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=61128 CPUtime=1.52 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 9027 7196 0 0 138 7 4 3 20 0 1 0 28668880 62595072 8609 18446744073709551615 4194304 5184042 140737220121488 140737220118440 140667541836218 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 15282 8609 842 242 0 7844 0 Current children cumulated CPU time (s) 1.52 Current children cumulated vsize (KiB) 61128 [startup+3.10021 s] /proc/loadavg: 0.93 0.97 0.91 2/56 29350 /proc/meminfo: memFree=274492/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=69476 CPUtime=3.11 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 11478 7196 0 0 295 9 4 3 20 0 1 0 28668880 71143424 10290 18446744073709551615 4194304 5184042 140737220121488 140737220118920 140667541829160 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 17369 10290 842 242 0 9931 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 69476 Solver just ended. Dumping a history of the last processes samples [startup+3.20029 s] /proc/loadavg: 0.93 0.97 0.91 2/56 29350 /proc/meminfo: memFree=274492/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=69476 CPUtime=3.21 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 11498 7196 0 0 305 9 4 3 20 0 1 0 28668880 71143424 10310 18446744073709551615 4194304 5184042 140737220121488 140737220118920 140667541831411 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 17369 10310 842 242 0 9931 0 Current children cumulated CPU time (s) 3.21 Current children cumulated vsize (KiB) 69476 [startup+4.80021 s] /proc/loadavg: 0.93 0.97 0.91 2/56 29350 /proc/meminfo: memFree=273128/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=69476 CPUtime=4.8 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 11700 7196 0 0 464 9 4 3 20 0 1 0 28668880 71143424 10512 18446744073709551615 4194304 5184042 140737220121488 140737220114856 140667541829356 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 17369 10512 842 242 0 9931 0 Current children cumulated CPU time (s) 4.8 Current children cumulated vsize (KiB) 69476 [startup+5.20021 s] /proc/loadavg: 0.93 0.97 0.91 2/56 29350 /proc/meminfo: memFree=273128/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=69476 CPUtime=5.2 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 11748 7196 0 0 504 9 4 3 20 0 1 0 28668880 71143424 10560 18446744073709551615 4194304 5184042 140737220121488 140737220114856 140667541852251 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 17369 10560 842 242 0 9931 0 Current children cumulated CPU time (s) 5.2 Current children cumulated vsize (KiB) 69476 [startup+5.60312 s] /proc/loadavg: 0.93 0.97 0.91 2/56 29350 /proc/meminfo: memFree=272508/1022884 swapFree=0/0 [pid=29330] ppid=29329 vsize=69476 CPUtime=5.6 /proc/29330/stat : 29330 (cupt) R 29329 29330 17872 34816 17872 4202496 11796 7196 0 0 544 9 4 3 20 0 1 0 28668880 71143424 10608 18446744073709551615 4194304 5184042 140737220121488 140737220115752 140667541829168 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29330/statm: 17369 10608 842 242 0 9931 0 Current children cumulated CPU time (s) 5.6 Current children cumulated vsize (KiB) 69476 Child status: 1 Real time (s): 5.68063 CPU time (s): 5.68835 CPU user time (s): 5.55235 CPU system time (s): 0.136008 CPU usage (%): 100.136 Max. virtual memory (cumulated for all children) (KiB): 69476 getrusage(RUSAGE_CHILDREN,...) data: user time used= 5.55235 system time used= 0.136008 maximum resident set size= 43076 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 19024 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= 101 runsolver used 0.008 second user time and 0.020001 second system time The end