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/68.runsolver.aptitude aptitude -s -y --without-recommends install freecraft smartlist php3 sendxmpp inetutils-talk 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.06 1.05 0.97 2/55 21677 /proc/meminfo: memFree=910240/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=3152 CPUtime=0 /proc/21677/stat : 21677 (runsolver) R 21676 17863 17863 34816 17863 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28527323 3227648 32 18446744073709551615 134512640 134586868 4292050160 4292048208 4151505968 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.19949 s] /proc/loadavg: 1.06 1.05 0.97 2/55 21677 /proc/meminfo: memFree=910240/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=89152 CPUtime=0.19 /proc/21677/stat : 21677 (aptitude) R 21676 21677 17863 34816 17863 4202496 7869 1709 0 0 17 2 0 0 20 0 1 0 28527323 91291648 7662 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366672752 140450143377382 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 22288 7662 6726 1052 0 858 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 89152 [startup+0.20027 s] /proc/loadavg: 1.06 1.05 0.97 2/55 21677 /proc/meminfo: memFree=910240/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=89152 CPUtime=0.19 /proc/21677/stat : 21677 (aptitude) R 21676 21677 17863 34816 17863 4202496 7869 1709 0 0 17 2 0 0 20 0 1 0 28527323 91291648 7662 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366672752 140450143372497 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 22288 7662 6726 1052 0 858 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 89152 [startup+0.300188 s] /proc/loadavg: 1.06 1.05 0.97 2/55 21677 /proc/meminfo: memFree=910240/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=101864 CPUtime=0.29 /proc/21677/stat : 21677 (aptitude) R 21676 21677 17863 34816 17863 4202496 11708 1709 0 0 26 3 0 0 20 0 1 0 28527323 104308736 10756 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366672408 140450106064363 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 25466 10756 6746 1052 0 4036 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 101864 [startup+0.700209 s] /proc/loadavg: 1.06 1.05 0.97 2/55 21677 /proc/meminfo: memFree=910240/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=114104 CPUtime=0.68 /proc/21677/stat : 21677 (aptitude) R 21676 21677 17863 34816 17863 4202496 13703 1709 0 0 64 4 0 0 20 0 2 0 28527323 116842496 12075 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366674248 140450106034503 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 28526 12075 6977 1052 0 7096 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 114104 [startup+1.50024 s] /proc/loadavg: 1.06 1.05 0.97 2/57 21682 /proc/meminfo: memFree=889524/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=115492 CPUtime=1.48 /proc/21677/stat : 21677 (aptitude) R 21676 21677 17863 34816 17863 4202496 14532 2208 0 0 142 6 0 0 20 0 2 0 28527323 118263808 12302 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366669680 140450151100197 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 28873 12302 7066 1052 0 7443 0 [pid=21677/tid=21682] ppid=21676 vsize=115492 CPUtime=0 /proc/21677/task/21682/stat : 21682 (aptitude) S 21676 21677 17863 34816 17863 4202560 6 2208 0 0 0 0 0 0 20 0 2 0 28527367 118263808 12302 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051930112 140450117268180 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) 115492 [startup+3.10025 s] /proc/loadavg: 1.06 1.05 0.97 2/57 21683 /proc/meminfo: memFree=878984/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=213252 CPUtime=3.07 /proc/21677/stat : 21677 (aptitude) S 21676 21677 17863 34816 17863 4202496 23911 2208 0 0 297 10 0 0 20 0 2 0 28527323 218370048 20650 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366674736 140450117269067 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 53313 20650 7122 1052 0 31883 0 [pid=21677/tid=21682] ppid=21676 vsize=213252 CPUtime=1.24 /proc/21677/task/21682/stat : 21682 (aptitude) R 21676 21677 17863 34816 17863 4202560 9355 2208 0 0 120 4 0 0 20 0 2 0 28527367 218370048 20650 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051921448 140450151149899 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) 213252 [startup+6.30024 s] /proc/loadavg: 1.05 1.05 0.97 2/57 21683 /proc/meminfo: memFree=833104/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=241824 CPUtime=6.25 /proc/21677/stat : 21677 (aptitude) S 21676 21677 17863 34816 17863 4202496 31042 2208 0 0 614 11 0 0 20 0 2 0 28527323 247627776 27780 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366674736 140450117269067 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 60456 27780 7122 1052 0 39026 0 [pid=21677/tid=21682] ppid=21676 vsize=241824 CPUtime=4.42 /proc/21677/task/21682/stat : 21682 (aptitude) R 21676 21677 17863 34816 17863 4202560 16486 2208 0 0 437 5 0 0 20 0 2 0 28527367 247627776 27780 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051923816 140450151268807 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) 241824 Solver just ended. Dumping a history of the last processes samples [startup+6.40031 s] /proc/loadavg: 1.05 1.05 0.97 2/57 21683 /proc/meminfo: memFree=833104/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=242356 CPUtime=6.35 /proc/21677/stat : 21677 (aptitude) S 21676 21677 17863 34816 17863 4202496 31182 2208 0 0 624 11 0 0 20 0 2 0 28527323 248172544 27920 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366674736 140450117269067 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 60589 27920 7122 1052 0 39159 0 [pid=21677/tid=21682] ppid=21676 vsize=242356 CPUtime=4.52 /proc/21677/task/21682/stat : 21682 (aptitude) R 21676 21677 17863 34816 17863 4202560 16626 2208 0 0 447 5 0 0 20 0 2 0 28527367 248172544 27920 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051923640 140450151259891 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) 242356 [startup+8.00025 s] /proc/loadavg: 1.05 1.05 0.97 2/57 21683 /proc/meminfo: memFree=814380/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=256228 CPUtime=7.94 /proc/21677/stat : 21677 (aptitude) S 21676 21677 17863 34816 17863 4202496 34650 2208 0 0 782 12 0 0 20 0 2 0 28527323 262377472 31388 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366674736 140450117269067 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 64057 31388 7122 1052 0 42627 0 [pid=21677/tid=21682] ppid=21676 vsize=256228 CPUtime=6.11 /proc/21677/task/21682/stat : 21682 (aptitude) R 21676 21677 17863 34816 17863 4202560 20094 2208 0 0 605 6 0 0 20 0 2 0 28527367 262377472 31388 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051923768 140450151170571 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 7.94 Current children cumulated vsize (KiB) 256228 [startup+9.60025 s] /proc/loadavg: 1.05 1.05 0.97 2/57 21683 /proc/meminfo: memFree=804212/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=270096 CPUtime=9.54 /proc/21677/stat : 21677 (aptitude) S 21676 21677 17863 34816 17863 4202496 38147 2208 0 0 941 13 0 0 20 0 2 0 28527323 276578304 34856 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366674736 140450117269067 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 67524 34856 7122 1052 0 46094 0 [pid=21677/tid=21682] ppid=21676 vsize=270096 CPUtime=7.71 /proc/21677/task/21682/stat : 21682 (aptitude) R 21676 21677 17863 34816 17863 4202560 23591 2208 0 0 764 7 0 0 20 0 2 0 28527367 276578304 34856 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051923768 140450106676416 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) 270096 [startup+10.0032 s] /proc/loadavg: 1.05 1.05 0.97 2/57 21683 /proc/meminfo: memFree=795036/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=274980 CPUtime=9.93 /proc/21677/stat : 21677 (aptitude) S 21676 21677 17863 34816 17863 4202496 39369 2208 0 0 980 13 0 0 20 0 2 0 28527323 281579520 36074 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366674736 140450117269067 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 68745 36074 7123 1052 0 47315 0 [pid=21677/tid=21682] ppid=21676 vsize=274980 CPUtime=8.1 /proc/21677/task/21682/stat : 21682 (aptitude) R 21676 21677 17863 34816 17863 4202560 24813 2208 0 0 803 7 0 0 20 0 2 0 28527367 281579520 36074 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051921000 140450151220337 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 9.93 Current children cumulated vsize (KiB) 274980 [startup+10.4003 s] /proc/loadavg: 1.05 1.05 0.97 2/57 21683 /proc/meminfo: memFree=795036/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=276016 CPUtime=10.33 /proc/21677/stat : 21677 (aptitude) R 21676 21677 17863 34816 17863 4202496 41451 2208 0 0 1020 13 0 0 20 0 2 0 28527323 282640384 36402 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366670840 140450150725458 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 69004 36402 7172 1052 0 47567 0 [pid=21677/tid=21682] ppid=21676 vsize=276016 CPUtime=8.16 /proc/21677/task/21682/stat : 21682 (aptitude) S 21676 21677 17863 34816 17863 4202560 25040 2208 0 0 809 7 0 0 20 0 2 0 28527367 282640384 36402 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051930112 140450117268180 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.33 Current children cumulated vsize (KiB) 276016 [startup+10.5005 s] /proc/loadavg: 1.05 1.05 0.97 2/57 21683 /proc/meminfo: memFree=795036/1022884 swapFree=0/0 [pid=21677] ppid=21676 vsize=276016 CPUtime=10.44 /proc/21677/stat : 21677 (aptitude) R 21676 21677 17863 34816 17863 4202496 41666 2708 0 0 1026 17 0 1 20 0 2 0 28527323 282640384 34444 18446744073709551615 140450148524032 140450152831384 140735366682976 140735366679240 140450106389994 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/21677/statm: 69004 34444 7172 1052 0 47567 0 [pid=21677/tid=21682] ppid=21676 vsize=276016 CPUtime=8.17 /proc/21677/task/21682/stat : 21682 (aptitude) S 21676 21677 17863 34816 17863 4202560 25040 2708 0 0 809 7 0 1 20 0 2 0 28527367 282640384 34444 18446744073709551615 140450148524032 140450152831384 140735366682976 140450051930112 140450117268180 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 10.44 Current children cumulated vsize (KiB) 276016 Child status: 0 Real time (s): 10.5358 CPU time (s): 10.4927 CPU user time (s): 10.2686 CPU system time (s): 0.224014 CPU usage (%): 99.5908 Max. virtual memory (cumulated for all children) (KiB): 276016 getrusage(RUSAGE_CHILDREN,...) data: user time used= 10.2686 system time used= 0.224014 maximum resident set size= 145968 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 44522 page faults= 0 swaps= 0 block input operations= 0 block output operations= 16 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 77 involuntary context switches= 234 runsolver used 0.004 second user time and 0.052003 second system time The end