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/86.runsolver.aptitude aptitude -s -y --without-recommends install libxi-dev dict-freedict-nld-deu ftdi-eeprom libdmalloc4-dev vdr-plugin-sky 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.01 1.06 1.01 2/55 22070 /proc/meminfo: memFree=849972/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=3152 CPUtime=0 /proc/22070/stat : 22070 (runsolver) R 22069 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28602181 3227648 32 18446744073709551615 134512640 134586868 4286930960 4286929008 4151235632 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.153776 s] /proc/loadavg: 1.01 1.06 1.01 2/55 22070 /proc/meminfo: memFree=849972/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=89152 CPUtime=0.15 /proc/22070/stat : 22070 (aptitude) R 22069 22070 17863 34816 17863 4202496 7773 1708 0 0 12 2 0 1 20 0 1 0 28602181 91291648 7574 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884316880 140304215154376 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 22288 7574 6663 1052 0 858 0 Current children cumulated CPU time (s) 0.15 Current children cumulated vsize (KiB) 89152 [startup+0.20028 s] /proc/loadavg: 1.01 1.06 1.01 2/55 22070 /proc/meminfo: memFree=849972/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=89152 CPUtime=0.2 /proc/22070/stat : 22070 (aptitude) R 22069 22070 17863 34816 17863 4202496 7869 1708 0 0 17 2 0 1 20 0 1 0 28602181 91291648 7662 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884315392 140304214608210 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 22288 7662 6726 1052 0 858 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 89152 [startup+0.300269 s] /proc/loadavg: 1.01 1.06 1.01 2/55 22070 /proc/meminfo: memFree=849972/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=101864 CPUtime=0.29 /proc/22070/stat : 22070 (aptitude) R 22069 22070 17863 34816 17863 4202496 11708 1708 0 0 25 3 0 1 20 0 1 0 28602181 104308736 10756 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884315048 140304177294871 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 25466 10756 6746 1052 0 4036 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 101864 [startup+0.700205 s] /proc/loadavg: 1.01 1.06 1.01 2/55 22070 /proc/meminfo: memFree=849972/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=114092 CPUtime=0.69 /proc/22070/stat : 22070 (aptitude) R 22069 22070 17863 34816 17863 4202496 13700 1708 0 0 63 5 0 1 20 0 2 0 28602181 116830208 12072 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884316888 140304221965405 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 28523 12072 6977 1052 0 7093 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 114092 [startup+1.50024 s] /proc/loadavg: 1.01 1.06 1.01 2/57 22075 /proc/meminfo: memFree=829256/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=115500 CPUtime=1.48 /proc/22070/stat : 22070 (aptitude) R 22069 22070 17863 34816 17863 4202496 14565 2206 0 0 141 6 0 1 20 0 2 0 28602181 118272000 12306 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884312320 140304177254806 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 28875 12306 7066 1052 0 7445 0 [pid=22070/tid=22075] ppid=22069 vsize=115500 CPUtime=0.01 /proc/22070/task/22075/stat : 22075 (aptitude) S 22069 22070 17863 34816 17863 4202560 6 2206 0 0 0 0 0 1 20 0 2 0 28602225 118272000 12306 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123160576 140304188498644 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) 115500 [startup+3.10024 s] /proc/loadavg: 1.00 1.06 1.01 2/57 22076 /proc/meminfo: memFree=812516/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=142448 CPUtime=3.08 /proc/22070/stat : 22070 (aptitude) S 22069 22070 17863 34816 17863 4202496 22313 2206 0 0 297 10 0 1 20 0 2 0 28602181 145866752 19330 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884317376 140304188499531 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 35612 19330 7123 1052 0 14182 0 [pid=22070/tid=22075] ppid=22069 vsize=142448 CPUtime=1.22 /proc/22070/task/22075/stat : 22075 (aptitude) R 22069 22070 17863 34816 17863 4202560 7737 2206 0 0 118 3 0 1 20 0 2 0 28602225 145866752 19330 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123149384 140304222400786 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) 142448 [startup+6.30024 s] /proc/loadavg: 1.00 1.06 1.01 2/57 22076 /proc/meminfo: memFree=775192/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=243420 CPUtime=6.27 /proc/22070/stat : 22070 (aptitude) S 22069 22070 17863 34816 17863 4202496 31401 2206 0 0 612 14 0 1 20 0 2 0 28602181 249262080 28193 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884317376 140304188499531 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 60855 28193 7123 1052 0 39425 0 [pid=22070/tid=22075] ppid=22069 vsize=243420 CPUtime=4.41 /proc/22070/task/22075/stat : 22075 (aptitude) R 22069 22070 17863 34816 17863 4202560 16824 2206 0 0 432 8 0 1 20 0 2 0 28602225 249262080 28193 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123151896 140304188490161 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 243420 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.00 1.06 1.01 2/57 22076 /proc/meminfo: memFree=775192/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=244484 CPUtime=6.37 /proc/22070/stat : 22070 (aptitude) S 22069 22070 17863 34816 17863 4202496 31697 2206 0 0 622 14 0 1 20 0 2 0 28602181 250351616 28454 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884317376 140304188499531 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 61121 28454 7123 1052 0 39691 0 [pid=22070/tid=22075] ppid=22069 vsize=244484 CPUtime=4.51 /proc/22070/task/22075/stat : 22075 (aptitude) R 22069 22070 17863 34816 17863 4202560 17120 2206 0 0 442 8 0 1 20 0 2 0 28602225 250351616 28454 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123151848 140304222364662 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 6.37 Current children cumulated vsize (KiB) 244484 [startup+7.20024 s] /proc/loadavg: 1.00 1.06 1.01 2/57 22076 /proc/meminfo: memFree=763660/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=251100 CPUtime=7.16 /proc/22070/stat : 22070 (aptitude) S 22069 22070 17863 34816 17863 4202496 33338 2206 0 0 701 14 0 1 20 0 2 0 28602181 257126400 30092 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884317376 140304188499531 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 62775 30092 7123 1052 0 41345 0 [pid=22070/tid=22075] ppid=22069 vsize=251100 CPUtime=5.3 /proc/22070/task/22075/stat : 22075 (aptitude) R 22069 22070 17863 34816 17863 4202560 18761 2206 0 0 521 8 0 1 20 0 2 0 28602225 257126400 30092 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123151944 140304177264776 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 7.16 Current children cumulated vsize (KiB) 251100 [startup+7.60023 s] /proc/loadavg: 1.00 1.06 1.01 2/57 22076 /proc/meminfo: memFree=763660/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=254664 CPUtime=7.56 /proc/22070/stat : 22070 (aptitude) S 22069 22070 17863 34816 17863 4202496 34252 2206 0 0 740 15 0 1 20 0 2 0 28602181 260775936 31006 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884317376 140304188499531 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 63666 31006 7123 1052 0 42236 0 [pid=22070/tid=22075] ppid=22069 vsize=254664 CPUtime=5.7 /proc/22070/task/22075/stat : 22075 (aptitude) R 22069 22070 17863 34816 17863 4202560 19675 2206 0 0 560 9 0 1 20 0 2 0 28602225 260775936 31006 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123151896 140304221955867 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 7.56 Current children cumulated vsize (KiB) 254664 [startup+8.00024 s] /proc/loadavg: 1.00 1.06 1.01 2/57 22076 /proc/meminfo: memFree=752872/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=255016 CPUtime=7.96 /proc/22070/stat : 22070 (aptitude) R 22069 22070 17863 34816 17863 4202496 35768 2206 0 0 780 15 0 1 20 0 2 0 28602181 261136384 31279 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884313480 140304177971995 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 63754 31279 7172 1052 0 42317 0 [pid=22070/tid=22075] ppid=22069 vsize=255016 CPUtime=5.72 /proc/22070/task/22075/stat : 22075 (aptitude) S 22069 22070 17863 34816 17863 4202560 19712 2206 0 0 562 9 0 1 20 0 2 0 28602225 261136384 31279 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123160576 140304188498644 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 7.96 Current children cumulated vsize (KiB) 255016 [startup+8.10024 s] /proc/loadavg: 1.00 1.06 1.01 2/57 22076 /proc/meminfo: memFree=752872/1022884 swapFree=0/0 [pid=22070] ppid=22069 vsize=255016 CPUtime=8.06 /proc/22070/stat : 22070 (aptitude) R 22069 22070 17863 34816 17863 4202496 36589 2206 0 0 790 15 0 1 20 0 2 0 28602181 261136384 31280 18446744073709551615 140304219754496 140304224061848 140736884325616 140736884317432 140304214650900 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/22070/statm: 63754 31280 7179 1052 0 42317 0 [pid=22070/tid=22075] ppid=22069 vsize=255016 CPUtime=5.72 /proc/22070/task/22075/stat : 22075 (aptitude) S 22069 22070 17863 34816 17863 4202560 19712 2206 0 0 562 9 0 1 20 0 2 0 28602225 261136384 31280 18446744073709551615 140304219754496 140304224061848 140736884325616 140304123160576 140304188498644 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 8.06 Current children cumulated vsize (KiB) 255016 Child status: 0 Real time (s): 8.17537 CPU time (s): 8.14451 CPU user time (s): 7.9205 CPU system time (s): 0.224014 CPU usage (%): 99.6225 Max. virtual memory (cumulated for all children) (KiB): 255016 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.92049 system time used= 0.224014 maximum resident set size= 125436 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 40042 page faults= 0 swaps= 0 block input operations= 0 block output operations= 112 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 74 involuntary context switches= 185 runsolver used 0.024001 second user time and 0.016001 second system time The end