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/121.runsolver.aptitude aptitude -s -y --without-recommends remove libguile-ltdl-1 libjpeg62-dev libxrender1 kopete libxft2 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.15 1.09 1.04 2/55 24419 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=3152 CPUtime=0 /proc/24419/stat : 24419 (runsolver) R 24418 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29225024 3227648 33 18446744073709551615 134512640 134586868 4291397408 4291395456 4152112176 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.109233 s] /proc/loadavg: 1.15 1.09 1.04 2/55 24419 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=100508 CPUtime=0.09 /proc/24419/stat : 24419 (aptitude) R 24418 24419 17863 34816 17863 4202496 10508 1708 0 0 7 2 0 0 20 0 1 0 29225024 102920192 10308 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776562848 139996828541794 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 25127 10308 9133 1052 0 1122 0 Current children cumulated CPU time (s) 0.09 Current children cumulated vsize (KiB) 100508 [startup+0.200273 s] /proc/loadavg: 1.15 1.09 1.04 2/55 24419 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=100508 CPUtime=0.18 /proc/24419/stat : 24419 (aptitude) R 24418 24419 17863 34816 17863 4202496 10608 1708 0 0 16 2 0 0 20 0 1 0 29225024 102920192 10408 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776562848 139996827981387 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 25127 10408 9233 1052 0 1122 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 100508 [startup+0.300266 s] /proc/loadavg: 1.15 1.09 1.04 2/55 24419 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=111108 CPUtime=0.28 /proc/24419/stat : 24419 (aptitude) R 24418 24419 17863 34816 17863 4202496 13342 1708 0 0 25 3 0 0 20 0 1 0 29225024 113774592 13134 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776563232 139996790679072 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 27777 13134 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.28 Current children cumulated vsize (KiB) 111108 [startup+0.700199 s] /proc/loadavg: 1.15 1.09 1.04 2/55 24419 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=125780 CPUtime=0.69 /proc/24419/stat : 24419 (aptitude) R 24418 24419 17863 34816 17863 4202496 17468 1708 0 0 64 5 0 0 20 0 2 0 29225024 128798720 14740 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776563624 139996835736912 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 31445 14740 9514 1052 0 7440 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 125780 [startup+1.5003 s] /proc/loadavg: 1.15 1.09 1.04 2/57 24424 /proc/meminfo: memFree=837852/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=131964 CPUtime=1.48 /proc/24419/stat : 24419 (aptitude) R 24418 24419 17863 34816 17863 4202496 19310 1708 0 0 143 5 0 0 20 0 2 0 29225024 135131136 16579 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776561880 139996790651257 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 32991 16579 9569 1052 0 8986 0 [pid=24419/tid=24424] ppid=24418 vsize=131964 CPUtime=0 /proc/24419/task/24424/stat : 24424 (aptitude) S 24418 24419 17863 34816 17863 4202560 4 1708 0 0 0 0 0 0 20 0 2 0 29225088 135131136 16579 18446744073709551615 139996833140736 139996837448088 140735776571584 139996723968000 139996801884884 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) 131964 [startup+3.10024 s] /proc/loadavg: 1.15 1.09 1.04 2/57 24424 /proc/meminfo: memFree=837232/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=218928 CPUtime=3.07 /proc/24419/stat : 24419 (aptitude) S 24418 24419 17863 34816 17863 4202496 24749 1708 0 0 301 6 0 0 20 0 2 0 29225024 224182272 22017 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776563344 139996801885771 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 54732 22017 9659 1052 0 30727 0 [pid=24419/tid=24424] ppid=24418 vsize=218928 CPUtime=0.55 /proc/24419/task/24424/stat : 24424 (aptitude) R 24418 24419 17863 34816 17863 4202560 5300 1708 0 0 54 1 0 0 20 0 2 0 29225088 224182272 22017 18446744073709551615 139996833140736 139996837448088 140735776571584 139996723958488 139996835725566 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) 218928 Solver just ended. Dumping a history of the last processes samples [startup+3.2003 s] /proc/loadavg: 1.15 1.09 1.04 2/57 24424 /proc/meminfo: memFree=837232/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=221700 CPUtime=3.17 /proc/24419/stat : 24419 (aptitude) S 24418 24419 17863 34816 17863 4202496 25438 1708 0 0 310 7 0 0 20 0 2 0 29225024 227020800 22706 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776563344 139996801885771 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 55425 22706 9659 1052 0 31420 0 [pid=24419/tid=24424] ppid=24418 vsize=221700 CPUtime=0.65 /proc/24419/task/24424/stat : 24424 (aptitude) R 24418 24419 17863 34816 17863 4202560 5989 1708 0 0 63 2 0 0 20 0 2 0 29225088 227020800 22706 18446744073709551615 139996833140736 139996837448088 140735776571584 139996723959672 139996835773863 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.17 Current children cumulated vsize (KiB) 221700 [startup+4.80023 s] /proc/loadavg: 1.13 1.09 1.04 2/57 24424 /proc/meminfo: memFree=773248/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=276800 CPUtime=4.76 /proc/24419/stat : 24419 (aptitude) S 24418 24419 17863 34816 17863 4202496 39231 1708 0 0 464 12 0 0 20 0 2 0 29225024 283443200 36499 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776563344 139996801885771 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 69200 36499 9660 1052 0 45195 0 [pid=24419/tid=24424] ppid=24418 vsize=276800 CPUtime=2.24 /proc/24419/task/24424/stat : 24424 (aptitude) R 24418 24419 17863 34816 17863 4202560 19782 1708 0 0 217 7 0 0 20 0 2 0 29225088 283443200 36499 18446744073709551615 139996833140736 139996837448088 140735776571584 139996723961528 139996834490880 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.76 Current children cumulated vsize (KiB) 276800 [startup+5.60312 s] /proc/loadavg: 1.13 1.09 1.04 2/57 24424 /proc/meminfo: memFree=742868/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=292912 CPUtime=5.56 /proc/24419/stat : 24419 (aptitude) S 24418 24419 17863 34816 17863 4202496 43256 1708 0 0 542 14 0 0 20 0 2 0 29225024 299941888 40524 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776563344 139996801885771 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 73228 40524 9662 1052 0 49223 0 [pid=24419/tid=24424] ppid=24418 vsize=292912 CPUtime=3.03 /proc/24419/task/24424/stat : 24424 (aptitude) R 24418 24419 17863 34816 17863 4202560 23807 1708 0 0 294 9 0 0 20 0 2 0 29225088 299941888 40524 18446744073709551615 139996833140736 139996837448088 140735776571584 139996723959464 139996790651257 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 5.56 Current children cumulated vsize (KiB) 292912 [startup+6.00025 s] /proc/loadavg: 1.13 1.09 1.04 2/57 24424 /proc/meminfo: memFree=742868/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=293272 CPUtime=5.96 /proc/24419/stat : 24419 (aptitude) R 24418 24419 17863 34816 17863 4202496 43560 1708 0 0 581 15 0 0 20 0 2 0 29225024 300310528 40787 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776559448 139996835266085 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 73318 40787 9711 1052 0 49306 0 [pid=24419/tid=24424] ppid=24418 vsize=293272 CPUtime=3.11 /proc/24419/task/24424/stat : 24424 (aptitude) S 24418 24419 17863 34816 17863 4202560 23869 1708 0 0 302 9 0 0 20 0 2 0 29225088 300310528 40787 18446744073709551615 139996833140736 139996837448088 140735776571584 139996723968000 139996801884884 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 5.96 Current children cumulated vsize (KiB) 293272 [startup+6.20025 s] /proc/loadavg: 1.13 1.09 1.04 2/57 24424 /proc/meminfo: memFree=742868/1022884 swapFree=0/0 [pid=24419] ppid=24418 vsize=293272 CPUtime=6.16 /proc/24419/stat : 24419 (aptitude) R 24418 24419 17863 34816 17863 4202496 43642 1708 0 0 601 15 0 0 20 0 2 0 29225024 300310528 40771 18446744073709551615 139996833140736 139996837448088 140735776571584 140735776563688 139996790632054 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24419/statm: 73318 40771 9719 1052 0 49306 0 [pid=24419/tid=24424] ppid=24418 vsize=293272 CPUtime=3.11 /proc/24419/task/24424/stat : 24424 (aptitude) S 24418 24419 17863 34816 17863 4202560 23869 1708 0 0 302 9 0 0 20 0 2 0 29225088 300310528 40771 18446744073709551615 139996833140736 139996837448088 140735776571584 139996723968000 139996801884884 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.16 Current children cumulated vsize (KiB) 293272 Child status: 0 Real time (s): 6.28807 CPU time (s): 6.26439 CPU user time (s): 6.07638 CPU system time (s): 0.188011 CPU usage (%): 99.6235 Max. virtual memory (cumulated for all children) (KiB): 293272 getrusage(RUSAGE_CHILDREN,...) data: user time used= 6.07638 system time used= 0.188011 maximum resident set size= 163356 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 45417 page faults= 0 swaps= 0 block input operations= 0 block output operations= 88 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 62 involuntary context switches= 152 runsolver used 0.004 second user time and 0.028001 second system time The end