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/logs/152.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove kdbg libksieve0 libice-dev kwifimanager libart-2.0-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.08 0.89 0.47 2/55 25136 /proc/meminfo: memFree=281692/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=3152 CPUtime=0 /proc/25136/stat : 25136 (runsolver) R 25135 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28219024 3227648 32 18446744073709551615 134512640 134586868 4287596960 4287595008 4152194096 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.141413 s] /proc/loadavg: 1.08 0.89 0.47 2/55 25136 /proc/meminfo: memFree=281692/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=33904 CPUtime=0.16 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 1950 7197 0 0 8 1 4 3 20 0 1 0 28219024 34717696 1768 18446744073709551615 4194304 5184042 140737018204512 140737018201704 140672107925593 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 8476 1768 729 242 0 1038 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 33904 [startup+0.200284 s] /proc/loadavg: 1.08 0.89 0.47 2/55 25136 /proc/meminfo: memFree=281692/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=39976 CPUtime=0.22 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 3524 7197 0 0 13 2 4 3 20 0 1 0 28219024 40935424 3334 18446744073709551615 4194304 5184042 140737018204512 140737018202088 140672107863604 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 9994 3334 795 242 0 2556 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 39976 [startup+0.300288 s] /proc/loadavg: 1.08 0.89 0.47 2/55 25136 /proc/meminfo: memFree=281692/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=50000 CPUtime=0.32 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 6083 7197 0 0 22 3 4 3 20 0 1 0 28219024 51200000 5892 18446744073709551615 4194304 5184042 140737018204512 140737018201800 140672124204134 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 12500 5892 842 242 0 5062 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 50000 [startup+0.700214 s] /proc/loadavg: 1.08 0.89 0.47 2/55 25136 /proc/meminfo: memFree=281692/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=56624 CPUtime=0.72 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 7869 7197 0 0 61 4 4 3 20 0 1 0 28219024 57982976 7476 18446744073709551615 4194304 5184042 140737018204512 140737018198808 140672124220275 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 14156 7476 842 242 0 6718 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 56624 [startup+1.50023 s] /proc/loadavg: 1.07 0.89 0.48 2/56 25156 /proc/meminfo: memFree=252172/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=60024 CPUtime=1.51 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 9001 7197 0 0 140 4 4 3 20 0 1 0 28219024 61464576 8351 18446744073709551615 4194304 5184042 140737018204512 140737018198776 140672124204584 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 15006 8351 842 242 0 7568 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 60024 [startup+3.10022 s] /proc/loadavg: 1.07 0.89 0.48 2/56 25156 /proc/meminfo: memFree=250064/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=68540 CPUtime=3.11 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 11611 7197 0 0 298 6 4 3 20 0 1 0 28219024 70184960 10448 18446744073709551615 4194304 5184042 140737018204512 140737018197880 140672124146278 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 17135 10448 842 242 0 9697 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 68540 [startup+6.30021 s] /proc/loadavg: 1.07 0.89 0.48 2/56 25156 /proc/meminfo: memFree=238408/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=75308 CPUtime=6.29 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 14179 7197 0 0 616 6 4 3 20 0 1 0 28219024 77115392 11991 18446744073709551615 4194304 5184042 140737018204512 140737018201816 140672124204756 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 18827 11991 842 242 0 11389 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 75308 Solver just ended. Dumping a history of the last processes samples [startup+6.40029 s] /proc/loadavg: 1.07 0.89 0.48 2/56 25156 /proc/meminfo: memFree=238408/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=75308 CPUtime=6.39 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 14196 7197 0 0 626 6 4 3 20 0 1 0 28219024 77115392 12008 18446744073709551615 4194304 5184042 140737018204512 140737018201816 140672116286027 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 18827 12008 842 242 0 11389 0 Current children cumulated CPU time (s) 6.39 Current children cumulated vsize (KiB) 75308 [startup+6.80021 s] /proc/loadavg: 1.07 0.89 0.48 2/56 25156 /proc/meminfo: memFree=236796/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=75308 CPUtime=6.79 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 14283 7197 0 0 666 6 4 3 20 0 1 0 28219024 77115392 12095 18446744073709551615 4194304 5184042 140737018204512 140737018201816 140672124216739 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 18827 12095 842 242 0 11389 0 Current children cumulated CPU time (s) 6.79 Current children cumulated vsize (KiB) 75308 [startup+6.90022 s] /proc/loadavg: 1.07 0.89 0.48 2/56 25156 /proc/meminfo: memFree=236796/1022884 swapFree=0/0 [pid=25136] ppid=25135 vsize=66856 CPUtime=6.89 /proc/25136/stat : 25136 (cupt) R 25135 25136 17872 34816 17872 4202496 14299 7197 0 0 675 7 4 3 20 0 1 0 28219024 68460544 10130 18446744073709551615 4194304 5184042 140737018204512 140737018203960 140672107851382 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25136/statm: 16714 10130 853 242 0 9276 0 Current children cumulated CPU time (s) 6.89 Current children cumulated vsize (KiB) 66856 Child status: 1 Real time (s): 6.92094 CPU time (s): 6.92043 CPU user time (s): 6.80842 CPU system time (s): 0.112007 CPU usage (%): 99.9927 Max. virtual memory (cumulated for all children) (KiB): 75308 getrusage(RUSAGE_CHILDREN,...) data: user time used= 6.80842 system time used= 0.112007 maximum resident set size= 48444 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 21516 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 121 runsolver used 0.012 second user time and 0.028001 second system time The end