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/34.runsolver.aptitude aptitude -s -y --without-recommends install proj xfonts-cronyx-misc tdb-tools latex209-base textedit.app 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.06 1.05 1.00 2/55 23207 /proc/meminfo: memFree=869344/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=3152 CPUtime=0 /proc/23207/stat : 23207 (runsolver) R 23206 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28865766 3227648 32 18446744073709551615 134512640 134586868 4293586544 4293584592 4151551024 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.190399 s] /proc/loadavg: 1.06 1.05 1.00 2/55 23207 /proc/meminfo: memFree=869344/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=100508 CPUtime=0.17 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 10604 1708 0 0 15 2 0 0 20 0 1 0 28865766 102920192 10405 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649104 139732545165171 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 25127 10405 9231 1052 0 1122 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 100508 [startup+0.200285 s] /proc/loadavg: 1.06 1.05 1.00 2/55 23207 /proc/meminfo: memFree=869344/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=100508 CPUtime=0.19 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 10605 1708 0 0 16 3 0 0 20 0 1 0 28865766 102920192 10406 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649104 139732545165179 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 25127 10406 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 100508 [startup+0.300261 s] /proc/loadavg: 1.06 1.05 1.00 2/55 23207 /proc/meminfo: memFree=869344/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=111108 CPUtime=0.28 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 12572 1708 0 0 25 3 0 0 20 0 1 0 28865766 113774592 12365 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649432 139732552455788 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 27777 12365 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 111108 [startup+0.700202 s] /proc/loadavg: 1.06 1.05 1.00 2/55 23207 /proc/meminfo: memFree=869344/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=123288 CPUtime=0.68 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 17027 1708 0 0 59 9 0 0 20 0 2 0 28865766 126246912 14302 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002653624 139732545148453 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 30822 14302 9482 1052 0 6817 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123288 [startup+1.50023 s] /proc/loadavg: 1.06 1.05 1.00 2/57 23212 /proc/meminfo: memFree=841064/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=132396 CPUtime=1.48 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 19435 1708 0 0 138 10 0 0 20 0 2 0 28865766 135573504 16706 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002648192 139732551953138 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 33099 16706 9585 1052 0 9094 0 [pid=23207/tid=23212] ppid=23206 vsize=132396 CPUtime=0 /proc/23207/task/23212/stat : 23212 (aptitude) S 23206 23207 17863 34816 17863 4202560 4 1708 0 0 0 0 0 0 20 0 2 0 28865832 135573504 16706 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441151488 139732519068372 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 132396 [startup+3.10024 s] /proc/loadavg: 1.06 1.05 1.00 2/57 23213 /proc/meminfo: memFree=839816/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=133904 CPUtime=3.07 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 20608 2212 0 0 291 16 0 0 20 0 2 0 28865766 137117696 16947 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002644656 139732516633558 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 33476 16947 9644 1052 0 9471 0 [pid=23207/tid=23212] ppid=23206 vsize=133904 CPUtime=0 /proc/23207/task/23212/stat : 23212 (aptitude) S 23206 23207 17863 34816 17863 4202560 6 2212 0 0 0 0 0 0 20 0 2 0 28865832 137117696 16947 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441151488 139732519068372 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.07 Current children cumulated vsize (KiB) 133904 [startup+6.30024 s] /proc/loadavg: 1.05 1.05 1.00 2/57 23213 /proc/meminfo: memFree=796424/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=245644 CPUtime=6.25 /proc/23207/stat : 23207 (aptitude) S 23206 23207 17863 34816 17863 4202496 33173 2212 0 0 605 20 0 0 20 0 2 0 28865766 251539456 28749 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649600 139732519069259 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 61411 28749 9700 1052 0 37406 0 [pid=23207/tid=23212] ppid=23206 vsize=245644 CPUtime=3.17 /proc/23207/task/23212/stat : 23212 (aptitude) R 23206 23207 17863 34816 17863 4202560 12564 2212 0 0 313 4 0 0 20 0 2 0 28865832 251539456 28749 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441143160 139732507834745 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.25 Current children cumulated vsize (KiB) 245644 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.05 1.05 1.00 2/57 23213 /proc/meminfo: memFree=796424/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=245908 CPUtime=6.35 /proc/23207/stat : 23207 (aptitude) S 23206 23207 17863 34816 17863 4202496 33249 2212 0 0 615 20 0 0 20 0 2 0 28865766 251809792 28825 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649600 139732519069259 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 61477 28825 9700 1052 0 37472 0 [pid=23207/tid=23212] ppid=23206 vsize=245908 CPUtime=3.27 /proc/23207/task/23212/stat : 23212 (aptitude) R 23206 23207 17863 34816 17863 4202560 12640 2212 0 0 323 4 0 0 20 0 2 0 28865832 251809792 28825 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441145016 139732507905952 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.35 Current children cumulated vsize (KiB) 245908 [startup+9.60024 s] /proc/loadavg: 1.05 1.05 1.00 2/57 23213 /proc/meminfo: memFree=779188/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=267344 CPUtime=9.54 /proc/23207/stat : 23207 (aptitude) S 23206 23207 17863 34816 17863 4202496 38736 2212 0 0 931 23 0 0 20 0 2 0 28865766 273760256 34171 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649600 139732519069259 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 66836 34171 9700 1052 0 42831 0 [pid=23207/tid=23212] ppid=23206 vsize=267344 CPUtime=6.45 /proc/23207/task/23212/stat : 23212 (aptitude) R 23206 23207 17863 34816 17863 4202560 18127 2212 0 0 638 7 0 0 20 0 2 0 28865832 273760256 34171 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441142760 139732507815595 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 9.54 Current children cumulated vsize (KiB) 267344 [startup+10.4002 s] /proc/loadavg: 1.05 1.05 1.00 2/57 23213 /proc/meminfo: memFree=768276/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=274208 CPUtime=10.33 /proc/23207/stat : 23207 (aptitude) S 23206 23207 17863 34816 17863 4202496 40437 2212 0 0 1010 23 0 0 20 0 2 0 28865766 280788992 35871 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649600 139732519069259 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 68552 35871 9700 1052 0 44547 0 [pid=23207/tid=23212] ppid=23206 vsize=274208 CPUtime=7.25 /proc/23207/task/23212/stat : 23212 (aptitude) R 23206 23207 17863 34816 17863 4202560 19828 2212 0 0 718 7 0 0 20 0 2 0 28865832 280788992 35871 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441142808 139732507834695 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.33 Current children cumulated vsize (KiB) 274208 [startup+11.2002 s] /proc/loadavg: 1.05 1.05 1.00 2/57 23213 /proc/meminfo: memFree=760836/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=276768 CPUtime=11.13 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 43836 2212 0 0 1089 24 0 0 20 0 2 0 28865766 283410432 36722 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649544 139732545723965 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 69192 36722 9749 1052 0 45180 0 [pid=23207/tid=23212] ppid=23206 vsize=276768 CPUtime=7.59 /proc/23207/task/23212/stat : 23212 (aptitude) S 23206 23207 17863 34816 17863 4202560 20457 2212 0 0 752 7 0 0 20 0 2 0 28865832 283410432 36722 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441151488 139732519068372 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.13 Current children cumulated vsize (KiB) 276768 [startup+11.4002 s] /proc/loadavg: 1.05 1.05 1.00 2/57 23213 /proc/meminfo: memFree=760836/1022884 swapFree=0/0 [pid=23207] ppid=23206 vsize=276768 CPUtime=11.33 /proc/23207/stat : 23207 (aptitude) R 23206 23207 17863 34816 17863 4202496 44137 2712 0 0 1102 30 0 1 20 0 2 0 28865766 283410432 36628 18446744073709551615 139732550324224 139732554631576 140737002657840 140737002649656 139732508168261 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23207/statm: 69192 36628 9749 1052 0 45180 0 [pid=23207/tid=23212] ppid=23206 vsize=276768 CPUtime=7.6 /proc/23207/task/23212/stat : 23212 (aptitude) S 23206 23207 17863 34816 17863 4202560 20457 2712 0 0 752 7 0 1 20 0 2 0 28865832 283410432 36628 18446744073709551615 139732550324224 139732554631576 140737002657840 139732441151488 139732519068372 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.33 Current children cumulated vsize (KiB) 276768 Child status: 0 Real time (s): 11.4757 CPU time (s): 11.4287 CPU user time (s): 11.0527 CPU system time (s): 0.376023 CPU usage (%): 99.5904 Max. virtual memory (cumulated for all children) (KiB): 276768 getrusage(RUSAGE_CHILDREN,...) data: user time used= 11.0527 system time used= 0.376023 maximum resident set size= 147508 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 47361 page faults= 0 swaps= 0 block input operations= 0 block output operations= 136 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 78 involuntary context switches= 240 runsolver used 0.016001 second user time and 0.040002 second system time The end