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/120.runsolver.aptitude aptitude -s -y --without-recommends remove khangman libpt-plugins-oss gstreamer0.8-vorbis libgtk2.0-common libwmf0.2-7 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.16 1.10 1.04 2/55 24412 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=3152 CPUtime=0 /proc/24412/stat : 24412 (runsolver) R 24411 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29224574 3227648 32 18446744073709551615 134512640 134586868 4290587232 4290585280 4151780400 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.137017 s] /proc/loadavg: 1.16 1.10 1.04 2/55 24412 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=100508 CPUtime=0.13 /proc/24412/stat : 24412 (aptitude) R 24411 24412 17863 34816 17863 4202496 10592 1710 0 0 10 2 1 0 20 0 1 0 29224574 102920192 10393 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926431712 139744174252450 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 25127 10393 9218 1052 0 1122 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 100508 [startup+0.200268 s] /proc/loadavg: 1.16 1.10 1.04 2/55 24412 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=100508 CPUtime=0.19 /proc/24412/stat : 24412 (aptitude) R 24411 24412 17863 34816 17863 4202496 10607 1710 0 0 16 2 1 0 20 0 1 0 29224574 102920192 10408 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926431712 139744173696465 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 25127 10408 9233 1052 0 1122 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 100508 [startup+0.300256 s] /proc/loadavg: 1.16 1.10 1.04 2/55 24412 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=111108 CPUtime=0.29 /proc/24412/stat : 24412 (aptitude) R 24411 24412 17863 34816 17863 4202496 13342 1710 0 0 25 3 1 0 20 0 1 0 29224574 113774592 13135 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926431560 139744136433377 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 27777 13135 9303 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.700195 s] /proc/loadavg: 1.16 1.10 1.04 2/55 24412 /proc/meminfo: memFree=865884/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=131664 CPUtime=0.69 /proc/24412/stat : 24412 (aptitude) R 24411 24412 17863 34816 17863 4202496 19168 1710 0 0 61 7 1 0 20 0 2 0 29224574 134823936 16440 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926431720 139744145157085 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 32916 16440 9527 1052 0 8911 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 131664 [startup+1.50022 s] /proc/loadavg: 1.16 1.10 1.04 2/57 24417 /proc/meminfo: memFree=837852/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=131940 CPUtime=1.49 /proc/24412/stat : 24412 (aptitude) R 24411 24412 17863 34816 17863 4202496 19310 1710 0 0 141 7 1 0 20 0 2 0 29224574 135106560 16580 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926434696 139744180574429 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 32985 16580 9576 1052 0 8980 0 [pid=24412/tid=24417] ppid=24411 vsize=131940 CPUtime=0.01 /proc/24412/task/24417/stat : 24417 (aptitude) S 24411 24412 17863 34816 17863 4202560 4 1710 0 0 0 0 1 0 20 0 2 0 29224633 135106560 16580 18446744073709551615 139744178851840 139744183159192 140735926440448 139744069679104 139744147595988 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 131940 [startup+3.10025 s] /proc/loadavg: 1.16 1.10 1.04 2/57 24417 /proc/meminfo: memFree=837232/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=170784 CPUtime=3.08 /proc/24412/stat : 24412 (aptitude) S 24411 24412 17863 34816 17863 4202496 29091 1710 0 0 297 10 1 0 20 0 2 0 29224574 174882816 26360 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926432208 139744147596875 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 42696 26360 9662 1052 0 18691 0 [pid=24412/tid=24417] ppid=24411 vsize=170784 CPUtime=0.69 /proc/24412/task/24417/stat : 24417 (aptitude) R 24411 24412 17863 34816 17863 4202560 9652 1710 0 0 66 2 1 0 20 0 2 0 29224633 174882816 26360 18446744073709551615 139744178851840 139744183159192 140735926440448 139744069669000 139744181081237 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 170784 Solver just ended. Dumping a history of the last processes samples [startup+3.20032 s] /proc/loadavg: 1.16 1.10 1.04 2/57 24417 /proc/meminfo: memFree=837232/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=172632 CPUtime=3.18 /proc/24412/stat : 24412 (aptitude) S 24411 24412 17863 34816 17863 4202496 29552 1710 0 0 307 10 1 0 20 0 2 0 29224574 176775168 26821 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926432208 139744147596875 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 43158 26821 9662 1052 0 19153 0 [pid=24412/tid=24417] ppid=24411 vsize=172632 CPUtime=0.8 /proc/24412/task/24417/stat : 24417 (aptitude) R 24411 24412 17863 34816 17863 4202560 10113 1710 0 0 76 3 1 0 20 0 2 0 29224633 176775168 26821 18446744073709551615 139744178851840 139744183159192 140735926440448 139744069670552 139744181053211 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.18 Current children cumulated vsize (KiB) 172632 [startup+4.00023 s] /proc/loadavg: 1.15 1.09 1.04 2/57 24417 /proc/meminfo: memFree=795320/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=245892 CPUtime=3.98 /proc/24412/stat : 24412 (aptitude) S 24411 24412 17863 34816 17863 4202496 31492 1710 0 0 386 11 1 0 20 0 2 0 29224574 251793408 28761 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926432208 139744147596875 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 61473 28761 9662 1052 0 37468 0 [pid=24412/tid=24417] ppid=24411 vsize=245892 CPUtime=1.6 /proc/24412/task/24417/stat : 24417 (aptitude) R 24411 24412 17863 34816 17863 4202560 12052 1710 0 0 155 4 1 0 20 0 2 0 29224633 251793408 28761 18446744073709551615 139744178851840 139744183159192 140735926440448 139744069670552 139744145161195 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.98 Current children cumulated vsize (KiB) 245892 [startup+4.40025 s] /proc/loadavg: 1.15 1.09 1.04 2/57 24417 /proc/meminfo: memFree=788252/1022884 swapFree=0/0 [pid=24412] ppid=24411 vsize=246316 CPUtime=4.38 /proc/24412/stat : 24412 (aptitude) R 24411 24412 17863 34816 17863 4202496 31830 1710 0 0 426 11 1 0 20 0 2 0 29224574 252227584 28972 18446744073709551615 139744178851840 139744183159192 140735926440448 140735926432552 139744180562064 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/24412/statm: 61579 28972 9719 1052 0 37567 0 [pid=24412/tid=24417] ppid=24411 vsize=246316 CPUtime=1.68 /proc/24412/task/24417/stat : 24417 (aptitude) S 24411 24412 17863 34816 17863 4202560 12156 1710 0 0 163 4 1 0 20 0 2 0 29224633 252227584 28972 18446744073709551615 139744178851840 139744183159192 140735926440448 139744069679104 139744147595988 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 4.38 Current children cumulated vsize (KiB) 246316 Child status: 0 Real time (s): 4.48733 CPU time (s): 4.47228 CPU user time (s): 4.32827 CPU system time (s): 0.144009 CPU usage (%): 99.6647 Max. virtual memory (cumulated for all children) (KiB): 246316 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.32827 system time used= 0.144009 maximum resident set size= 116248 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 33608 page faults= 0 swaps= 0 block input operations= 0 block output operations= 16 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 60 involuntary context switches= 123 runsolver used 0.008 second user time and 0.020001 second system time The end