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/90.runsolver.aptitude aptitude -s -y --without-recommends install wmtemp php3-cgi-mysql xbindkeys openoffice.org-l10n-zh-tw itcl3.1 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.23 1.15 1.05 2/55 24169 /proc/meminfo: memFree=963436/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=3152 CPUtime=0 /proc/24169/stat : 24169 (runsolver) R 24168 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29139569 3227648 32 18446744073709551615 134512640 134586868 4288007184 4288005232 4151944240 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24169/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.124598 s] /proc/loadavg: 1.23 1.15 1.05 2/55 24169 /proc/meminfo: memFree=963436/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=7872 CPUtime=0 /proc/24169/stat : 24169 (aptitude) D 24168 24169 17863 34816 17863 4202496 117 0 3 0 0 0 0 0 20 0 1 0 29139569 8060928 39 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369890552 139866996643363 0 0 0 0 0 0 0 17 0 0 0 11 0 0 /proc/24169/statm: 1968 39 30 1052 0 29 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 7872 [startup+0.200381 s] /proc/loadavg: 1.23 1.15 1.05 2/55 24169 /proc/meminfo: memFree=963436/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=28716 CPUtime=0 /proc/24169/stat : 24169 (aptitude) D 24168 24169 17863 34816 17863 4202496 154 0 11 0 0 0 0 0 20 0 1 0 29139569 29405184 77 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369890168 139866996643363 0 0 0 0 0 0 0 17 0 0 0 19 0 0 /proc/24169/statm: 7179 77 50 1052 0 33 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 28716 [startup+0.300368 s] /proc/loadavg: 1.23 1.15 1.05 2/55 24169 /proc/meminfo: memFree=963436/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=48572 CPUtime=0 /proc/24169/stat : 24169 (aptitude) D 24168 24169 17863 34816 17863 4202496 186 0 19 0 0 0 0 0 20 0 1 0 29139569 49737728 111 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369889368 139866996642526 0 0 0 0 0 0 0 17 0 0 0 28 0 0 /proc/24169/statm: 12143 111 68 1052 0 66 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 48572 [startup+0.700408 s] /proc/loadavg: 1.23 1.15 1.05 2/55 24169 /proc/meminfo: memFree=963436/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=100508 CPUtime=0.02 /proc/24169/stat : 24169 (aptitude) D 24168 24169 17863 34816 17863 4202496 2684 1705 41 4 0 2 0 0 20 0 1 0 29139569 102920192 2526 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369885024 139866993833882 0 134217728 4096 0 0 0 0 17 0 0 0 60 0 0 /proc/24169/statm: 25127 2526 1352 1052 0 1122 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 100508 [startup+1.50021 s] /proc/loadavg: 1.23 1.15 1.05 1/56 24173 /proc/meminfo: memFree=955740/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=100508 CPUtime=0.19 /proc/24169/stat : 24169 (aptitude) R 24168 24169 17863 34816 17863 4202496 10438 1705 167 4 17 2 0 0 20 0 1 0 29139569 102920192 10406 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369884816 139866955971232 0 134217728 4096 0 0 0 0 17 0 0 0 122 0 0 /proc/24169/statm: 25127 10406 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 100508 [startup+3.10021 s] /proc/loadavg: 1.23 1.15 1.05 1/56 24173 /proc/meminfo: memFree=887788/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=131932 CPUtime=1.2 /proc/24169/stat : 24169 (aptitude) R 24168 24169 17863 34816 17863 4202496 19141 1705 167 4 108 12 0 0 20 0 2 0 29139569 135098368 16578 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369883904 139866965097424 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 183 0 0 /proc/24169/statm: 32983 16578 9585 1052 0 8978 0 Current children cumulated CPU time (s) 1.2 Current children cumulated vsize (KiB) 131932 heavy processes: Solver just ended. Dumping a history of the last processes samples [startup+3.20336 s] /proc/loadavg: 1.21 1.15 1.05 3/57 24174 /proc/meminfo: memFree=842892/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=131932 CPUtime=1.3 /proc/24169/stat : 24169 (aptitude) R 24168 24169 17863 34816 17863 4202496 19157 1705 167 4 118 12 0 0 20 0 2 0 29139569 135098368 16594 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369883904 139867000419259 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 183 0 0 /proc/24169/statm: 32983 16594 9585 1052 0 8978 0 [pid=24169/tid=24174] ppid=24168 vsize=131932 CPUtime=0 /proc/24169/task/24174/stat : 24174 (aptitude) S 24168 24169 17863 34816 17863 4202560 4 1705 0 4 0 0 0 0 20 0 2 0 29139828 135098368 16594 18446744073709551615 139866998784000 139867003091352 140733369893552 139866889611264 139866967528148 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.3 Current children cumulated vsize (KiB) 131932 [startup+4.00025 s] /proc/loadavg: 1.21 1.15 1.05 2/57 24174 /proc/meminfo: memFree=842644/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=133688 CPUtime=2.04 /proc/24169/stat : 24169 (aptitude) R 24168 24169 17863 34816 17863 4202496 20094 2201 168 6 192 12 0 0 20 0 2 0 29139569 136896512 16773 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369885576 139867001022672 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 184 0 0 /proc/24169/statm: 33422 16773 9637 1052 0 9417 0 [pid=24169/tid=24174] ppid=24168 vsize=133688 CPUtime=0 /proc/24169/task/24174/stat : 24174 (aptitude) S 24168 24169 17863 34816 17863 4202560 6 2201 0 6 0 0 0 0 20 0 2 0 29139828 136896512 16773 18446744073709551615 139866998784000 139867003091352 140733369893552 139866889611264 139866967528148 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 2.04 Current children cumulated vsize (KiB) 133688 [startup+4.80024 s] /proc/loadavg: 1.21 1.15 1.05 2/57 24175 /proc/meminfo: memFree=841404/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=139496 CPUtime=2.85 /proc/24169/stat : 24169 (aptitude) S 24168 24169 17863 34816 17863 4202496 22576 2201 168 6 271 14 0 0 20 0 2 0 29139569 142843904 18582 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369885312 139866967529035 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 184 0 0 /proc/24169/statm: 34874 18582 9691 1052 0 10869 0 [pid=24169/tid=24174] ppid=24168 vsize=139496 CPUtime=0.17 /proc/24169/task/24174/stat : 24174 (aptitude) R 24168 24169 17863 34816 17863 4202560 2415 2201 0 6 16 1 0 0 20 0 2 0 29139828 142843904 18582 18446744073709551615 139866998784000 139867003091352 140733369893552 139866889603304 139866993607778 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 2.85 Current children cumulated vsize (KiB) 139496 [startup+5.20025 s] /proc/loadavg: 1.21 1.15 1.05 2/57 24175 /proc/meminfo: memFree=841404/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=142164 CPUtime=3.25 /proc/24169/stat : 24169 (aptitude) R 24168 24169 17863 34816 17863 4202496 26238 2201 168 6 310 15 0 0 20 0 2 0 29139569 145575936 19316 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369881416 139867000990375 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 184 0 0 /proc/24169/statm: 35541 19316 9742 1052 0 11529 0 [pid=24169/tid=24174] ppid=24168 vsize=142164 CPUtime=0.47 /proc/24169/task/24174/stat : 24174 (aptitude) S 24168 24169 17863 34816 17863 4202560 3582 2201 0 6 45 2 0 0 20 0 2 0 29139828 145575936 19316 18446744073709551615 139866998784000 139867003091352 140733369893552 139866889611264 139866967528148 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.25 Current children cumulated vsize (KiB) 142164 [startup+5.30025 s] /proc/loadavg: 1.21 1.15 1.05 2/57 24175 /proc/meminfo: memFree=841404/1022884 swapFree=0/0 [pid=24169] ppid=24168 vsize=142164 CPUtime=3.35 /proc/24169/stat : 24169 (aptitude) R 24168 24169 17863 34816 17863 4202496 26238 2201 168 6 320 15 0 0 20 0 2 0 29139569 145575936 19316 18446744073709551615 139866998784000 139867003091352 140733369893552 140733369885624 139866993608152 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 184 0 0 /proc/24169/statm: 35541 19316 9742 1052 0 11529 0 [pid=24169/tid=24174] ppid=24168 vsize=142164 CPUtime=0.47 /proc/24169/task/24174/stat : 24174 (aptitude) S 24168 24169 17863 34816 17863 4202560 3582 2201 0 6 45 2 0 0 20 0 2 0 29139828 145575936 19316 18446744073709551615 139866998784000 139867003091352 140733369893552 139866889611264 139866967528148 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.35 Current children cumulated vsize (KiB) 142164 Child status: 0 Real time (s): 5.3508 CPU time (s): 3.41621 CPU user time (s): 3.2242 CPU system time (s): 0.192012 CPU usage (%): 63.8449 Max. virtual memory (cumulated for all children) (KiB): 142164 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.2242 system time used= 0.192012 maximum resident set size= 77276 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 29180 page faults= 174 swaps= 0 block input operations= 185008 block output operations= 8 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 1798 involuntary context switches= 109 runsolver used 0.016001 second user time and 0.016001 second system time The end