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/19.runsolver.aptitude aptitude -s -y --without-recommends install gnome-gpg hostap-modules-2.6.8-4-386 rarpd shntool lesstif2 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.05 1.05 1.01 2/55 23064 /proc/meminfo: memFree=870196/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=3152 CPUtime=0 /proc/23064/stat : 23064 (runsolver) R 23063 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28792400 3227648 33 18446744073709551615 134512640 134586868 4287533232 4287531280 4151596080 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.185334 s] /proc/loadavg: 1.05 1.05 1.01 2/55 23064 /proc/meminfo: memFree=870196/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=100508 CPUtime=0.18 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 10601 1708 0 0 13 4 1 0 20 0 1 0 28792400 102920192 10402 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839564096 139863785779703 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 25127 10402 9228 1052 0 1122 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 100508 [startup+0.200285 s] /proc/loadavg: 1.05 1.05 1.01 2/55 23064 /proc/meminfo: memFree=870196/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=100508 CPUtime=0.19 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 10605 1708 0 0 14 4 1 0 20 0 1 0 28792400 102920192 10406 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839564096 139863785780689 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 25127 10406 9232 1052 0 1122 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 100508 [startup+0.300265 s] /proc/loadavg: 1.05 1.05 1.01 2/55 23064 /proc/meminfo: memFree=870196/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=104484 CPUtime=0.29 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 11628 1708 0 0 24 4 1 0 20 0 1 0 28792400 106991616 11421 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839564488 139863793084509 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 26121 11421 9300 1052 0 2116 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 104484 [startup+0.700196 s] /proc/loadavg: 1.05 1.05 1.01 2/55 23064 /proc/meminfo: memFree=870196/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=123288 CPUtime=0.69 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 17028 1708 0 0 60 8 1 0 20 0 2 0 28792400 126246912 14302 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839568616 139863785779577 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 30822 14302 9482 1052 0 6817 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 123288 [startup+1.50023 s] /proc/loadavg: 1.05 1.05 1.01 2/57 23069 /proc/meminfo: memFree=841916/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=132416 CPUtime=1.48 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 19432 1708 0 0 138 9 1 0 20 0 2 0 28792400 135593984 16702 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839563184 139863748446344 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 33104 16702 9585 1052 0 9099 0 [pid=23064/tid=23069] ppid=23063 vsize=132416 CPUtime=0.01 /proc/23064/task/23069/stat : 23069 (aptitude) S 23063 23064 17863 34816 17863 4202560 4 1708 0 0 0 0 1 0 20 0 2 0 28792466 135593984 16702 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681763328 139863759680212 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) 132416 [startup+3.10024 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=840792/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=133788 CPUtime=3.08 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 20584 2206 0 0 293 14 1 0 20 0 2 0 28792400 136998912 16937 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839559648 139863749088483 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 33447 16937 9644 1052 0 9442 0 [pid=23064/tid=23069] ppid=23063 vsize=133788 CPUtime=0.01 /proc/23064/task/23069/stat : 23069 (aptitude) S 23063 23064 17863 34816 17863 4202560 6 2206 0 0 0 0 1 0 20 0 2 0 28792466 136998912 16937 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681763328 139863759680212 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) 133788 [startup+6.30025 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=797400/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=245400 CPUtime=6.26 /proc/23064/stat : 23064 (aptitude) S 23063 23064 17863 34816 17863 4202496 33096 2206 0 0 607 18 1 0 20 0 2 0 28792400 251289600 28689 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839564592 139863759681099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 61350 28689 9700 1052 0 37345 0 [pid=23064/tid=23069] ppid=23063 vsize=245400 CPUtime=3.15 /proc/23064/task/23069/stat : 23069 (aptitude) R 23063 23064 17863 34816 17863 4202560 12511 2206 0 0 310 4 1 0 20 0 2 0 28792466 251289600 28689 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681756904 139863791525072 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) 245400 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=797400/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=245796 CPUtime=6.36 /proc/23064/stat : 23064 (aptitude) S 23063 23064 17863 34816 17863 4202496 33203 2206 0 0 617 18 1 0 20 0 2 0 28792400 251695104 28796 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839564592 139863759681099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 61449 28796 9700 1052 0 37444 0 [pid=23064/tid=23069] ppid=23063 vsize=245796 CPUtime=3.25 /proc/23064/task/23069/stat : 23069 (aptitude) R 23063 23064 17863 34816 17863 4202560 12618 2206 0 0 320 4 1 0 20 0 2 0 28792466 251695104 28796 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681754696 139863792564401 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.36 Current children cumulated vsize (KiB) 245796 [startup+9.60024 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=780536/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=266832 CPUtime=9.55 /proc/23064/stat : 23064 (aptitude) S 23063 23064 17863 34816 17863 4202496 38559 2206 0 0 932 22 1 0 20 0 2 0 28792400 273235968 34028 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839564592 139863759681099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 66708 34028 9700 1052 0 42703 0 [pid=23064/tid=23069] ppid=23063 vsize=266832 CPUtime=6.45 /proc/23064/task/23069/stat : 23069 (aptitude) R 23063 23064 17863 34816 17863 4202560 17974 2206 0 0 636 8 1 0 20 0 2 0 28792466 273235968 34028 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681754648 139863748446344 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 9.55 Current children cumulated vsize (KiB) 266832 [startup+10.4002 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=769500/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=273828 CPUtime=10.35 /proc/23064/stat : 23064 (aptitude) S 23063 23064 17863 34816 17863 4202496 40340 2206 0 0 1010 24 1 0 20 0 2 0 28792400 280399872 35786 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839564592 139863759681099 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 68457 35786 9700 1052 0 44452 0 [pid=23064/tid=23069] ppid=23063 vsize=273828 CPUtime=7.24 /proc/23064/task/23069/stat : 23069 (aptitude) R 23063 23064 17863 34816 17863 4202560 19755 2206 0 0 713 10 1 0 20 0 2 0 28792466 280399872 35786 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681754648 139863793671827 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.35 Current children cumulated vsize (KiB) 273828 [startup+11.2002 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=761564/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=276788 CPUtime=11.14 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 43744 2206 0 0 1087 26 1 0 20 0 2 0 28792400 283430912 36641 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839565032 139863793137435 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 69197 36641 9749 1052 0 45185 0 [pid=23064/tid=23069] ppid=23063 vsize=276788 CPUtime=7.63 /proc/23064/task/23069/stat : 23069 (aptitude) S 23063 23064 17863 34816 17863 4202560 20483 2206 0 0 752 10 1 0 20 0 2 0 28792466 283430912 36641 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681763328 139863759680212 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.14 Current children cumulated vsize (KiB) 276788 [startup+11.4002 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=761564/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=276788 CPUtime=11.33 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 44029 2704 0 0 1101 31 1 0 20 0 2 0 28792400 283430912 36807 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839562920 139863748780101 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 69197 36807 9749 1052 0 45185 0 [pid=23064/tid=23069] ppid=23063 vsize=276788 CPUtime=7.63 /proc/23064/task/23069/stat : 23069 (aptitude) S 23063 23064 17863 34816 17863 4202560 20483 2704 0 0 752 10 1 0 20 0 2 0 28792466 283430912 36807 18446744073709551615 139863790936064 139863795243416 140735839572832 139863681763328 139863759680212 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 11.33 Current children cumulated vsize (KiB) 276788 [startup+11.5008 s] /proc/loadavg: 1.04 1.05 1.01 2/57 23070 /proc/meminfo: memFree=761564/1022884 swapFree=0/0 [pid=23064] ppid=23063 vsize=261044 CPUtime=11.43 /proc/23064/stat : 23064 (aptitude) R 23063 23064 17863 34816 17863 4202496 44537 2704 0 0 1108 34 1 0 20 0 1 0 28792400 267309056 28864 18446744073709551615 139863790936064 139863795243416 140735839572832 140735839569880 139863748802026 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/23064/statm: 65261 28864 9752 1052 0 41249 0 Current children cumulated CPU time (s) 11.43 Current children cumulated vsize (KiB) 261044 Child status: 0 Real time (s): 11.5352 CPU time (s): 11.4847 CPU user time (s): 11.1047 CPU system time (s): 0.380023 CPU usage (%): 99.5619 Max. virtual memory (cumulated for all children) (KiB): 276788 getrusage(RUSAGE_CHILDREN,...) data: user time used= 11.1047 system time used= 0.380023 maximum resident set size= 147512 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 47350 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= 79 involuntary context switches= 254 runsolver used 0 second user time and 0.056003 second system time The end