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/12.runsolver.aptitude aptitude -s -y --without-recommends install titrax mozilla-locale-ko python2.2-egenix-mxstack libuuid1 websec 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.07 1.08 1.02 2/55 23001 /proc/meminfo: memFree=810168/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=3152 CPUtime=0 /proc/23001/stat : 23001 (runsolver) R 23000 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28765500 3227648 32 18446744073709551615 134512640 134586868 4288126560 4288124608 4151878704 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.202746 s] /proc/loadavg: 1.07 1.08 1.02 2/55 23001 /proc/meminfo: memFree=810168/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=100508 CPUtime=0.18 /proc/23001/stat : 23001 (aptitude) R 23000 23001 17863 34816 17863 4202496 10605 1709 0 0 16 2 0 0 20 0 1 0 28765500 102920192 10407 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687491648 139812889302611 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 25127 10407 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 100508 [startup+0.30035 s] /proc/loadavg: 1.07 1.08 1.02 2/55 23001 /proc/meminfo: memFree=810168/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=111108 CPUtime=0.29 /proc/23001/stat : 23001 (aptitude) R 23000 23001 17863 34816 17863 4202496 11701 1709 0 0 26 3 0 0 20 0 1 0 28765500 113774592 11495 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687491976 139812896593507 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 27777 11495 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.400276 s] /proc/loadavg: 1.07 1.08 1.02 2/55 23001 /proc/meminfo: memFree=810168/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=114404 CPUtime=0.39 /proc/23001/stat : 23001 (aptitude) R 23000 23001 17863 34816 17863 4202496 14882 1709 0 0 35 4 0 0 20 0 1 0 28765500 117149696 13930 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687489896 139812897386164 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 28601 13930 9312 1052 0 4596 0 Current children cumulated CPU time (s) 0.39 Current children cumulated vsize (KiB) 114404 [startup+0.700209 s] /proc/loadavg: 1.07 1.08 1.02 2/55 23001 /proc/meminfo: memFree=810168/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=123288 CPUtime=0.68 /proc/23001/stat : 23001 (aptitude) R 23000 23001 17863 34816 17863 4202496 17028 1709 0 0 62 6 0 0 20 0 2 0 28765500 126246912 14303 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687496168 139812889862015 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 30822 14303 9482 1052 0 6817 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 123288 [startup+1.50024 s] /proc/loadavg: 1.07 1.08 1.02 2/57 23006 /proc/meminfo: memFree=781888/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=132408 CPUtime=1.48 /proc/23001/stat : 23001 (aptitude) R 23000 23001 17863 34816 17863 4202496 19437 1709 0 0 142 6 0 0 20 0 2 0 28765500 135585792 16707 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687490736 139812896097468 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 33102 16707 9585 1052 0 9097 0 [pid=23001/tid=23006] ppid=23000 vsize=132408 CPUtime=0 /proc/23001/task/23006/stat : 23006 (aptitude) S 23000 23001 17863 34816 17863 4202560 4 1709 0 0 0 0 0 0 20 0 2 0 28765566 135585792 16707 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785289216 139812863206100 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) 132408 [startup+3.10024 s] /proc/loadavg: 1.07 1.08 1.02 2/57 23007 /proc/meminfo: memFree=780400/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=133912 CPUtime=3.08 /proc/23001/stat : 23001 (aptitude) R 23000 23001 17863 34816 17863 4202496 20614 2207 0 0 297 10 1 0 20 0 2 0 28765500 137125888 16942 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687487200 139812860775381 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 33478 16942 9644 1052 0 9473 0 [pid=23001/tid=23006] ppid=23000 vsize=133912 CPUtime=0.01 /proc/23001/task/23006/stat : 23006 (aptitude) S 23000 23001 17863 34816 17863 4202560 6 2207 0 0 0 0 1 0 20 0 2 0 28765566 137125888 16942 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785289216 139812863206100 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) 133912 [startup+6.30024 s] /proc/loadavg: 1.06 1.08 1.02 2/57 23007 /proc/meminfo: memFree=737248/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=179736 CPUtime=6.26 /proc/23001/stat : 23001 (aptitude) S 23000 23001 17863 34816 17863 4202496 33098 2207 0 0 608 17 1 0 20 0 2 0 28765500 184049664 28656 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687492144 139812863206987 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 44934 28656 9700 1052 0 20929 0 [pid=23001/tid=23006] ppid=23000 vsize=179736 CPUtime=3.13 /proc/23001/task/23006/stat : 23006 (aptitude) R 23000 23001 17863 34816 17863 4202560 12484 2207 0 0 306 6 1 0 20 0 2 0 28765566 184049664 28656 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785280536 139812897288718 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.26 Current children cumulated vsize (KiB) 179736 [startup+12.7002 s] /proc/loadavg: 1.06 1.08 1.02 2/57 23007 /proc/meminfo: memFree=682812/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=300320 CPUtime=12.63 /proc/23001/stat : 23001 (aptitude) S 23000 23001 17863 34816 17863 4202496 47404 2207 0 0 1240 22 1 0 20 0 2 0 28765500 307527680 42417 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687492144 139812863206987 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 75080 42417 9700 1052 0 51075 0 [pid=23001/tid=23006] ppid=23000 vsize=300320 CPUtime=9.51 /proc/23001/task/23006/stat : 23006 (aptitude) R 23000 23001 17863 34816 17863 4202560 26789 2207 0 0 938 12 1 0 20 0 2 0 28765566 307527680 42417 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785282648 139812897197715 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.63 Current children cumulated vsize (KiB) 300320 [startup+25.5032 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23007 /proc/meminfo: memFree=586960/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=392564 CPUtime=25.37 /proc/23001/stat : 23001 (aptitude) S 23000 23001 17863 34816 17863 4202496 70495 2207 0 0 2503 33 1 0 20 0 2 0 28765500 401985536 65432 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687492144 139812863206987 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 98141 65432 9700 1052 0 74136 0 [pid=23001/tid=23006] ppid=23000 vsize=392564 CPUtime=22.25 /proc/23001/task/23006/stat : 23006 (aptitude) R 23000 23001 17863 34816 17863 4202560 49880 2207 0 0 2201 23 1 0 20 0 2 0 28765566 401985536 65432 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785280536 139812897059001 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 25.37 Current children cumulated vsize (KiB) 392564 [startup+51.1003 s] /proc/loadavg: 1.03 1.07 1.02 2/57 23007 /proc/meminfo: memFree=390420/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=592280 CPUtime=50.86 /proc/23001/stat : 23001 (aptitude) S 23000 23001 17863 34816 17863 4202496 120466 2207 0 0 5023 62 1 0 20 0 2 0 28765500 606494720 115328 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687492144 139812863206987 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 148070 115328 9716 1052 0 124065 0 [pid=23001/tid=23006] ppid=23000 vsize=592280 CPUtime=47.73 /proc/23001/task/23006/stat : 23006 (aptitude) R 23000 23001 17863 34816 17863 4202560 99845 2207 0 0 4720 52 1 0 20 0 2 0 28765566 606494720 115328 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785280712 139812851953323 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 50.86 Current children cumulated vsize (KiB) 592280 [startup+102.3 s] /proc/loadavg: 1.08 1.07 1.02 2/57 23007 /proc/meminfo: memFree=10356/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=1102316 CPUtime=100.68 /proc/23001/stat : 23001 (aptitude) S 23000 23001 17863 34816 17863 4202496 248031 2207 103 0 9933 134 1 0 20 0 2 0 28765500 1128771584 242646 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687492144 139812863206987 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 275579 242646 9533 1052 0 251574 0 [pid=23001/tid=23006] ppid=23000 vsize=1102316 CPUtime=97.56 /proc/23001/task/23006/stat : 23006 (aptitude) R 23000 23001 17863 34816 17863 4202560 227410 2207 103 0 9631 124 1 0 20 0 2 0 28765566 1128771584 242646 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785283800 139812897199322 0 134217728 4096 0 0 0 0 -1 0 0 0 81 0 0 Current children cumulated CPU time (s) 100.68 Current children cumulated vsize (KiB) 1102316 Maximum VSize exceeded: sending signal-name then SIGKILL [startup+107.8 s] /proc/loadavg: 1.08 1.07 1.02 4/57 23007 /proc/meminfo: memFree=10244/1022884 swapFree=0/0 [pid=23001] ppid=23000 vsize=1151420 CPUtime=105.58 /proc/23001/stat : 23001 (aptitude) S 23000 23001 17863 34816 17863 4202496 260313 2207 145 0 10415 142 1 0 20 0 2 0 28765500 1179054080 246946 18446744073709551615 139812894461952 139812898769304 140736687500384 140736687492144 139812863206987 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23001/statm: 287855 246946 8861 1052 0 263850 0 [pid=23001/tid=23006] ppid=23000 vsize=1151420 CPUtime=102.45 /proc/23001/task/23006/stat : 23006 (aptitude) R 23000 23001 17863 34816 17863 4202560 239692 2207 145 0 10113 131 1 0 20 0 2 0 28765566 1179054080 246946 18446744073709551615 139812894461952 139812898769304 140736687500384 139812785280536 139812897353107 0 134217728 4096 0 0 0 0 -1 0 0 0 127 0 0 Current children cumulated CPU time (s) 105.58 Current children cumulated vsize (KiB) 1151420 Sending Terminated to process tree (bottom up) Sleeping 2 seconds Solver just ended. Dumping a history of the last processes samples Child ended because it received signal 15 (SIGTERM) Real time (s): 107.955 CPU time (s): 105.719 CPU user time (s): 104.227 CPU system time (s): 1.49209 CPU usage (%): 97.928 Max. virtual memory (cumulated for all children) (KiB): 1151420 getrusage(RUSAGE_CHILDREN,...) data: user time used= 104.227 system time used= 1.49209 maximum resident set size= 991296 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 262645 page faults= 147 swaps= 0 block input operations= 3440 block output operations= 72 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 443 involuntary context switches= 2543 runsolver used 0.132008 second user time and 0.372023 second system time The end