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/75.runsolver.aptitude aptitude -s -y --without-recommends install libgnomemm-2.6-1 libasis-3.15p-1 libdate-ical-perl python2.3-egenix-mxtools gkrellm-i8k 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.04 1.08 1.02 2/55 23810 /proc/meminfo: memFree=868524/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=3152 CPUtime=0 /proc/23810/stat : 23810 (runsolver) R 23809 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29051711 3227648 32 18446744073709551615 134512640 134586868 4290039632 4290037680 4151645232 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.140201 s] /proc/loadavg: 1.04 1.08 1.02 2/55 23810 /proc/meminfo: memFree=868524/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=100508 CPUtime=0.12 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 10579 1709 0 0 10 2 0 0 20 0 1 0 29051711 102920192 10380 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393296 140708345694038 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 25127 10380 9206 1052 0 1122 0 Current children cumulated CPU time (s) 0.12 Current children cumulated vsize (KiB) 100508 [startup+0.200281 s] /proc/loadavg: 1.04 1.08 1.02 2/55 23810 /proc/meminfo: memFree=868524/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=100508 CPUtime=0.18 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 10605 1709 0 0 16 2 0 0 20 0 1 0 29051711 102920192 10406 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393296 140708345678678 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 25127 10406 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 100508 [startup+0.30027 s] /proc/loadavg: 1.04 1.08 1.02 2/55 23810 /proc/meminfo: memFree=868524/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=111108 CPUtime=0.29 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 12373 1709 0 0 26 3 0 0 20 0 1 0 29051711 113774592 12166 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393624 140708352984659 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 27777 12166 9302 1052 0 3772 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 111108 [startup+0.700207 s] /proc/loadavg: 1.04 1.08 1.02 2/55 23810 /proc/meminfo: memFree=868524/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=123288 CPUtime=0.68 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 17027 1709 0 0 63 5 0 0 20 0 2 0 29051711 126246912 14302 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762397816 140708346253928 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 30822 14302 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.04 1.08 1.02 2/57 23815 /proc/meminfo: memFree=840244/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=132416 CPUtime=1.47 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 19432 1709 0 0 142 5 0 0 20 0 2 0 29051711 135593984 16703 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762392384 140708317162475 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 33104 16703 9585 1052 0 9099 0 [pid=23810/tid=23815] ppid=23809 vsize=132416 CPUtime=0 /proc/23810/task/23815/stat : 23815 (aptitude) S 23809 23810 17863 34816 17863 4202560 4 1709 0 0 0 0 0 0 20 0 2 0 29051776 135593984 16703 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241680384 140708319597268 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.47 Current children cumulated vsize (KiB) 132416 [startup+3.10025 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=838996/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=133888 CPUtime=3.07 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 20604 2208 0 0 298 9 0 0 20 0 2 0 29051711 137101312 16940 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762388848 140708353423336 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 33472 16940 9644 1052 0 9467 0 [pid=23810/tid=23815] ppid=23809 vsize=133888 CPUtime=0 /proc/23810/task/23815/stat : 23815 (aptitude) S 23809 23810 17863 34816 17863 4202560 6 2208 0 0 0 0 0 0 20 0 2 0 29051776 137101312 16940 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241680384 140708319597268 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) 133888 [startup+6.30024 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=796348/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=244860 CPUtime=6.25 /proc/23810/stat : 23810 (aptitude) S 23809 23810 17863 34816 17863 4202496 33047 2208 0 0 613 12 0 0 20 0 2 0 29051711 250736640 28547 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393792 140708319598155 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 61215 28547 9700 1052 0 37210 0 [pid=23810/tid=23815] ppid=23809 vsize=244860 CPUtime=3.17 /proc/23810/task/23815/stat : 23815 (aptitude) R 23809 23810 17863 34816 17863 4202560 12442 2208 0 0 315 2 0 0 20 0 2 0 29051776 250736640 28547 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241675880 140708352203273 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) 244860 Solver just ended. Dumping a history of the last processes samples [startup+6.40032 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=796348/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=245124 CPUtime=6.35 /proc/23810/stat : 23810 (aptitude) S 23809 23810 17863 34816 17863 4202496 33126 2208 0 0 623 12 0 0 20 0 2 0 29051711 251006976 28626 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393792 140708319598155 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 61281 28626 9700 1052 0 37276 0 [pid=23810/tid=23815] ppid=23809 vsize=245124 CPUtime=3.27 /proc/23810/task/23815/stat : 23815 (aptitude) R 23809 23810 17863 34816 17863 4202560 12521 2208 0 0 325 2 0 0 20 0 2 0 29051776 251006976 28626 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241671704 140708353499786 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) 245124 [startup+8.00024 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=780972/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=257928 CPUtime=7.95 /proc/23810/stat : 23810 (aptitude) S 23809 23810 17863 34816 17863 4202496 36363 2208 0 0 782 13 0 0 20 0 2 0 29051711 264118272 31810 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393792 140708319598155 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 64482 31810 9700 1052 0 40477 0 [pid=23810/tid=23815] ppid=23809 vsize=257928 CPUtime=4.87 /proc/23810/task/23815/stat : 23815 (aptitude) R 23809 23810 17863 34816 17863 4202560 15758 2208 0 0 484 3 0 0 20 0 2 0 29051776 264118272 31810 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241671704 140708353679960 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 7.95 Current children cumulated vsize (KiB) 257928 [startup+9.6003 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=774896/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=267564 CPUtime=9.54 /proc/23810/stat : 23810 (aptitude) S 23809 23810 17863 34816 17863 4202496 38799 2208 0 0 941 13 0 0 20 0 2 0 29051711 273985536 34219 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393792 140708319598155 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 66891 34219 9700 1052 0 42886 0 [pid=23810/tid=23815] ppid=23809 vsize=267564 CPUtime=6.46 /proc/23810/task/23815/stat : 23815 (aptitude) R 23809 23810 17863 34816 17863 4202560 18194 2208 0 0 643 3 0 0 20 0 2 0 29051776 273985536 34219 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241673912 140708308348672 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) 267564 [startup+10.4002 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=768076/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=270916 CPUtime=10.34 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 42315 2208 0 0 1020 14 0 0 20 0 2 0 29051711 277417984 35235 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762389896 140708352687766 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 67729 35235 9750 1052 0 43717 0 [pid=23810/tid=23815] ppid=23809 vsize=270916 CPUtime=6.96 /proc/23810/task/23815/stat : 23815 (aptitude) S 23809 23810 17863 34816 17863 4202560 19034 2208 0 0 692 4 0 0 20 0 2 0 29051776 277417984 35235 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241680384 140708319597268 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.34 Current children cumulated vsize (KiB) 270916 [startup+10.6002 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=768076/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=270916 CPUtime=10.53 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 42414 2208 0 0 1039 14 0 0 20 0 2 0 29051711 277417984 35278 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762391792 140708308556086 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 67729 35278 9750 1052 0 43717 0 [pid=23810/tid=23815] ppid=23809 vsize=270916 CPUtime=6.96 /proc/23810/task/23815/stat : 23815 (aptitude) S 23809 23810 17863 34816 17863 4202560 19034 2208 0 0 692 4 0 0 20 0 2 0 29051776 277417984 35278 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241680384 140708319597268 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.53 Current children cumulated vsize (KiB) 270916 [startup+10.7002 s] /proc/loadavg: 1.04 1.08 1.02 2/57 23816 /proc/meminfo: memFree=768076/1022884 swapFree=0/0 [pid=23810] ppid=23809 vsize=270916 CPUtime=10.63 /proc/23810/stat : 23810 (aptitude) R 23809 23810 17863 34816 17863 4202496 42657 2708 0 0 1044 18 1 0 20 0 2 0 29051711 277417984 35398 18446744073709551615 140708350853120 140708355160472 140733762402032 140733762393192 140708308363550 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23810/statm: 67729 35398 9750 1052 0 43717 0 [pid=23810/tid=23815] ppid=23809 vsize=270916 CPUtime=6.97 /proc/23810/task/23815/stat : 23815 (aptitude) S 23809 23810 17863 34816 17863 4202560 19034 2708 0 0 692 4 1 0 20 0 2 0 29051776 277417984 35398 18446744073709551615 140708350853120 140708355160472 140733762402032 140708241680384 140708319597268 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.63 Current children cumulated vsize (KiB) 270916 Child status: 0 Real time (s): 10.7991 CPU time (s): 10.7567 CPU user time (s): 10.5047 CPU system time (s): 0.252015 CPU usage (%): 99.6073 Max. virtual memory (cumulated for all children) (KiB): 270916 getrusage(RUSAGE_CHILDREN,...) data: user time used= 10.5047 system time used= 0.252015 maximum resident set size= 141696 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 45914 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= 75 involuntary context switches= 225 runsolver used 0.012 second user time and 0.040002 second system time The end