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/logs/23.runsolver.aptitude aptitude -s -y --without-recommends install snmp dcraw fbi libgdome2-xslt0 foomatic-filters 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.00 1.03 0.86 2/55 21038 /proc/meminfo: memFree=904496/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=3152 CPUtime=0 /proc/21038/stat : 21038 (runsolver) R 21037 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28351762 3227648 33 18446744073709551615 134512640 134586868 4288170192 4288168240 4152005680 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.187785 s] /proc/loadavg: 1.00 1.03 0.86 2/55 21038 /proc/meminfo: memFree=904496/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=89152 CPUtime=0.18 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 7776 1710 0 0 16 2 0 0 20 0 1 0 28351762 91291648 7575 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594189840 139907173816212 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 22288 7575 6665 1052 0 858 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 89152 [startup+0.200283 s] /proc/loadavg: 1.00 1.03 0.86 2/55 21038 /proc/meminfo: memFree=904496/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=89152 CPUtime=0.18 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 7870 1710 0 0 16 2 0 0 20 0 1 0 28351762 91291648 7661 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594188352 139907174371632 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 22288 7661 6726 1052 0 858 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 89152 [startup+0.300271 s] /proc/loadavg: 1.00 1.03 0.86 2/55 21038 /proc/meminfo: memFree=904496/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=101864 CPUtime=0.29 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 11709 1710 0 0 26 3 0 0 20 0 1 0 28351762 104308736 10755 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594188008 139907136511527 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 25466 10755 6746 1052 0 4036 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 101864 [startup+0.700194 s] /proc/loadavg: 1.00 1.03 0.86 2/55 21038 /proc/meminfo: memFree=904496/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=114112 CPUtime=0.68 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 13705 1710 0 0 64 4 0 0 20 0 2 0 28351762 116850688 12076 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594189848 139907179800203 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 28528 12076 6977 1052 0 7098 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 114112 [startup+1.50023 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21043 /proc/meminfo: memFree=883780/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=115528 CPUtime=1.47 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 14580 2208 0 0 141 6 0 0 20 0 2 0 28351762 118300672 12318 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190600 139907181982449 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 28882 12318 7073 1052 0 7452 0 [pid=21038/tid=21043] ppid=21037 vsize=115528 CPUtime=0 /proc/21038/task/21043/stat : 21043 (aptitude) S 21037 21038 17863 34816 17863 4202560 6 2208 0 0 0 0 0 0 20 0 2 0 28351806 118300672 12318 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082377216 139907147715284 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) 115528 [startup+3.10025 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=872620/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=149196 CPUtime=3.07 /proc/21038/stat : 21038 (aptitude) S 21037 21038 17863 34816 17863 4202496 23915 2208 0 0 298 9 0 0 20 0 2 0 28351762 152776704 21009 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190336 139907147716171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 37299 21009 7128 1052 0 15869 0 [pid=21038/tid=21043] ppid=21037 vsize=149196 CPUtime=1.18 /proc/21038/task/21043/stat : 21043 (aptitude) R 21037 21038 17863 34816 17863 4202560 9318 2208 0 0 116 2 0 0 20 0 2 0 28351806 152776704 21009 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082370824 139907136466864 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) 149196 [startup+6.30024 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=832692/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=237308 CPUtime=6.25 /proc/21038/stat : 21038 (aptitude) S 21037 21038 17863 34816 17863 4202496 29974 2208 0 0 615 10 0 0 20 0 2 0 28351762 243003392 26662 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190336 139907147716171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 59327 26662 7129 1052 0 37897 0 [pid=21038/tid=21043] ppid=21037 vsize=237308 CPUtime=4.37 /proc/21038/task/21043/stat : 21043 (aptitude) R 21037 21038 17863 34816 17863 4202560 15376 2208 0 0 434 3 0 0 20 0 2 0 28351806 243003392 26662 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082370824 139907181617461 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) 237308 [startup+12.7002 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=775900/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=291224 CPUtime=12.62 /proc/21038/stat : 21038 (aptitude) S 21037 21038 17863 34816 17863 4202496 43436 2208 0 0 1244 18 0 0 20 0 2 0 28351762 298213376 40121 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190336 139907147716171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 72806 40121 7131 1052 0 51376 0 [pid=21038/tid=21043] ppid=21037 vsize=291224 CPUtime=10.74 /proc/21038/task/21043/stat : 21043 (aptitude) R 21037 21038 17863 34816 17863 4202560 28838 2208 0 0 1063 11 0 0 20 0 2 0 28351806 298213376 40121 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082368664 139907179616542 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.62 Current children cumulated vsize (KiB) 291224 [startup+25.5002 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=677940/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=387076 CPUtime=25.36 /proc/21038/stat : 21038 (aptitude) S 21037 21038 17863 34816 17863 4202496 67369 2208 0 0 2507 29 0 0 20 0 2 0 28351762 396365824 64054 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190336 139907147716171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 96769 64054 7131 1052 0 75339 0 [pid=21038/tid=21043] ppid=21037 vsize=387076 CPUtime=23.48 /proc/21038/task/21043/stat : 21043 (aptitude) R 21037 21038 17863 34816 17863 4202560 52771 2208 0 0 2326 22 0 0 20 0 2 0 28351806 396365824 64054 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082368536 139907136471460 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 25.36 Current children cumulated vsize (KiB) 387076 Solver just ended. Dumping a history of the last processes samples [startup+25.6003 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=677940/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=388132 CPUtime=25.46 /proc/21038/stat : 21038 (aptitude) S 21037 21038 17863 34816 17863 4202496 67629 2208 0 0 2517 29 0 0 20 0 2 0 28351762 397447168 64314 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190336 139907147716171 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 97033 64314 7131 1052 0 75603 0 [pid=21038/tid=21043] ppid=21037 vsize=388132 CPUtime=23.58 /proc/21038/task/21043/stat : 21043 (aptitude) R 21037 21038 17863 34816 17863 4202560 53031 2208 0 0 2336 22 0 0 20 0 2 0 28351806 397447168 64314 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082368536 139907181773801 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 25.46 Current children cumulated vsize (KiB) 388132 [startup+26.4002 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=671616/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=391276 CPUtime=26.26 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 68582 2208 0 0 2596 30 0 0 20 0 2 0 28351762 400666624 65244 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190872 139907136462279 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 97819 65244 7179 1052 0 76382 0 [pid=21038/tid=21043] ppid=21037 vsize=391276 CPUtime=23.86 /proc/21038/task/21043/stat : 21043 (aptitude) S 21037 21038 17863 34816 17863 4202560 53818 2208 0 0 2363 23 0 0 20 0 2 0 28351806 400666624 65244 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082377216 139907147715284 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 26.26 Current children cumulated vsize (KiB) 391276 [startup+26.6002 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=671616/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=391276 CPUtime=26.46 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 70387 2208 0 0 2615 31 0 0 20 0 2 0 28351762 400666624 65229 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594190776 139907181175969 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 97819 65229 7181 1052 0 76382 0 [pid=21038/tid=21043] ppid=21037 vsize=391276 CPUtime=23.86 /proc/21038/task/21043/stat : 21043 (aptitude) S 21037 21038 17863 34816 17863 4202560 53818 2208 0 0 2363 23 0 0 20 0 2 0 28351806 400666624 65229 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082377216 139907147715284 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 26.46 Current children cumulated vsize (KiB) 391276 [startup+26.7002 s] /proc/loadavg: 1.00 1.03 0.86 2/57 21044 /proc/meminfo: memFree=671616/1022884 swapFree=0/0 [pid=21038] ppid=21037 vsize=391276 CPUtime=26.57 /proc/21038/stat : 21038 (aptitude) R 21037 21038 17863 34816 17863 4202496 70495 2707 0 0 2619 36 1 1 20 0 2 0 28351762 400666624 65286 18446744073709551615 139907178971136 139907183278488 140736594198576 140736594189896 139907136481657 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21038/statm: 97819 65286 7181 1052 0 76382 0 [pid=21038/tid=21043] ppid=21037 vsize=391276 CPUtime=23.88 /proc/21038/task/21043/stat : 21043 (aptitude) S 21037 21038 17863 34816 17863 4202560 53818 2707 0 0 2363 23 1 1 20 0 2 0 28351806 400666624 65286 18446744073709551615 139907178971136 139907183278488 140736594198576 139907082377216 139907147715284 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 26.57 Current children cumulated vsize (KiB) 391276 Child status: 0 Real time (s): 26.7812 CPU time (s): 26.6617 CPU user time (s): 26.2176 CPU system time (s): 0.444027 CPU usage (%): 99.5537 Max. virtual memory (cumulated for all children) (KiB): 391276 getrusage(RUSAGE_CHILDREN,...) data: user time used= 26.2176 system time used= 0.444027 maximum resident set size= 261180 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 73515 page faults= 0 swaps= 0 block input operations= 0 block output operations= 48 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 108 involuntary context switches= 507 runsolver used 0 second user time and 0.128008 second system time The end