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/111.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove ktuberling akode ttf-opensymbol libpopt-dev libwnck-common 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.99 0.99 0.96 2/55 435 /proc/meminfo: memFree=338380/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=3152 CPUtime=0 /proc/435/stat : 435 (runsolver) R 434 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29361902 3227648 32 18446744073709551615 134512640 134586868 4290870416 4290868464 4151555120 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.16042 s] /proc/loadavg: 0.99 0.99 0.96 2/55 435 /proc/meminfo: memFree=338380/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=34436 CPUtime=0.17 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 2087 7215 0 0 8 3 4 2 20 0 1 0 29361902 35262464 1905 18446744073709551615 4194304 5184042 140736778396336 140736778393528 139648422723713 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 8609 1905 729 242 0 1171 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 34436 [startup+0.200274 s] /proc/loadavg: 0.99 0.99 0.96 2/55 435 /proc/meminfo: memFree=338380/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=35360 CPUtime=0.21 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 2322 7215 0 0 10 5 4 2 20 0 1 0 29361902 36208640 2140 18446744073709551615 4194304 5184042 140736778396336 140736778393528 139648422661684 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 8840 2140 729 242 0 1402 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35360 [startup+0.300256 s] /proc/loadavg: 0.99 0.99 0.96 2/55 435 /proc/meminfo: memFree=338380/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=37984 CPUtime=0.31 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 3026 7215 0 0 19 6 4 2 20 0 1 0 29361902 38895616 2781 18446744073709551615 4194304 5184042 140736778396336 140736778393528 139648422592560 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 9496 2781 739 242 0 2058 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 37984 [startup+0.70021 s] /proc/loadavg: 0.99 0.99 0.96 2/55 435 /proc/meminfo: memFree=338380/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=63328 CPUtime=0.71 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 9470 7215 0 0 55 10 4 2 20 0 1 0 29361902 64847872 9216 18446744073709551615 4194304 5184042 140736778396336 140736778393640 139648431083968 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 15832 9216 851 242 0 8394 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 63328 [startup+1.50021 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=303288/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=65652 CPUtime=1.5 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 10156 7215 0 0 134 10 4 2 20 0 1 0 29361902 67227648 9708 18446744073709551615 4194304 5184042 140736778396336 140736778393640 139648438987528 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 16413 9708 851 242 0 8975 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 65652 [startup+3.10021 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=302048/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=67128 CPUtime=3.1 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 10655 7215 0 0 294 10 4 2 20 0 1 0 29361902 68739072 9950 18446744073709551615 4194304 5184042 140736778396336 140736778393768 139648439002836 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 16782 9950 851 242 0 9344 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 67128 [startup+6.30021 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=301180/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=67128 CPUtime=6.28 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 10885 7215 0 0 612 10 4 2 20 0 1 0 29361902 68739072 10180 18446744073709551615 4194304 5184042 140736778396336 140736778393768 139648422668434 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 16782 10180 851 242 0 9344 0 Current children cumulated CPU time (s) 6.28 Current children cumulated vsize (KiB) 67128 [startup+12.7002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=299320/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=69316 CPUtime=12.66 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 11867 7215 0 0 1248 12 4 2 20 0 1 0 29361902 70979584 10649 18446744073709551615 4194304 5184042 140736778396336 140736778393640 139648438949280 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 17329 10649 851 242 0 9891 0 Current children cumulated CPU time (s) 12.66 Current children cumulated vsize (KiB) 69316 [startup+25.5002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=294360/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=74620 CPUtime=25.41 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 14113 7215 0 0 2522 13 4 2 20 0 1 0 29361902 76410880 11870 18446744073709551615 4194304 5184042 140736778396336 140736778393640 139648439150704 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 18655 11870 851 242 0 11217 0 Current children cumulated CPU time (s) 25.41 Current children cumulated vsize (KiB) 74620 [startup+51.1002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=287044/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=82812 CPUtime=50.9 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 17965 7215 0 0 5067 17 4 2 20 0 1 0 29361902 84799488 13673 18446744073709551615 4194304 5184042 140736778396336 140736778393768 139648422658352 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 20703 13673 851 242 0 13265 0 Current children cumulated CPU time (s) 50.9 Current children cumulated vsize (KiB) 82812 Solver just ended. Dumping a history of the last processes samples [startup+51.2003 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=287044/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=82812 CPUtime=51 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 17971 7215 0 0 5077 17 4 2 20 0 1 0 29361902 84799488 13679 18446744073709551615 4194304 5184042 140736778396336 140736778393768 139648439002112 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 20703 13679 851 242 0 13265 0 Current children cumulated CPU time (s) 51 Current children cumulated vsize (KiB) 82812 [startup+54.4002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=283448/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=85376 CPUtime=54.19 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 18888 7215 0 0 5396 17 4 2 20 0 1 0 29361902 87425024 14596 18446744073709551615 4194304 5184042 140736778396336 140736778390632 139648431472479 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 21344 14596 851 242 0 13906 0 Current children cumulated CPU time (s) 54.19 Current children cumulated vsize (KiB) 85376 [startup+55.2002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=280968/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=87344 CPUtime=54.98 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 19475 7215 0 0 5475 17 4 2 20 0 1 0 29361902 89440256 15183 18446744073709551615 4194304 5184042 140736778396336 140736778389752 139648439002832 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 21836 15183 851 242 0 14398 0 Current children cumulated CPU time (s) 54.98 Current children cumulated vsize (KiB) 87344 [startup+56.0002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=280968/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=88148 CPUtime=55.78 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 19703 7215 0 0 5554 18 4 2 20 0 1 0 29361902 90263552 15411 18446744073709551615 4194304 5184042 140736778396336 140736778393640 139648422658865 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 22037 15411 851 242 0 14599 0 Current children cumulated CPU time (s) 55.78 Current children cumulated vsize (KiB) 88148 [startup+56.4002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=279108/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=105240 CPUtime=56.17 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 23999 7215 0 0 5593 18 4 2 20 0 1 0 29361902 107765760 15610 18446744073709551615 4194304 5184042 140736778396336 140736778393768 139648439002112 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 26310 15610 851 242 0 18872 0 Current children cumulated CPU time (s) 56.17 Current children cumulated vsize (KiB) 105240 [startup+56.5002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 455 /proc/meminfo: memFree=279108/1022884 swapFree=0/0 [pid=435] ppid=434 vsize=71960 CPUtime=56.28 /proc/435/stat : 435 (cupt) R 434 435 17872 34816 17872 4202496 24011 7215 0 0 5603 19 4 2 20 0 1 0 29361902 73687040 11396 18446744073709551615 4194304 5184042 140736778396336 140736778395784 139648422668333 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/435/statm: 17990 11396 862 242 0 10552 0 Current children cumulated CPU time (s) 56.28 Current children cumulated vsize (KiB) 71960 Child status: 1 Real time (s): 56.5324 CPU time (s): 56.3275 CPU user time (s): 56.0955 CPU system time (s): 0.232014 CPU usage (%): 99.6376 Max. virtual memory (cumulated for all children) (KiB): 105240 getrusage(RUSAGE_CHILDREN,...) data: user time used= 56.0955 system time used= 0.232014 maximum resident set size= 78824 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 31246 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= 857 runsolver used 0.060003 second user time and 0.180011 second system time The end