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/logs/153.runsolver.aptitude aptitude -s -y --without-recommends remove libcomerr2 console-data libhal-storage0 keduca libreadline4 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 Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 0.99 0.86 0.47 2/55 20715 /proc/meminfo: memFree=240676/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=54860 CPUtime=0 /proc/20715/stat : 20715 (aptitude) R 20714 20715 17863 34816 17863 4202496 613 0 0 0 0 0 0 0 20 0 1 0 28224110 56176640 513 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913769960 140426835547599 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 13715 513 419 1052 0 73 0 [startup+0.114714 s] /proc/loadavg: 0.99 0.86 0.47 2/55 20715 /proc/meminfo: memFree=240676/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=80316 CPUtime=0.09 /proc/20715/stat : 20715 (aptitude) R 20714 20715 17863 34816 17863 4202496 5570 1710 0 0 8 1 0 0 20 0 1 0 28224110 82243584 5367 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762016 140426794924711 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 20079 5367 4644 1052 0 670 0 Current children cumulated CPU time (s) 0.09 Current children cumulated vsize (KiB) 80316 [startup+0.200292 s] /proc/loadavg: 0.99 0.86 0.47 2/55 20715 /proc/meminfo: memFree=240676/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=89348 CPUtime=0.18 /proc/20715/stat : 20715 (aptitude) R 20714 20715 17863 34816 17863 4202496 8319 1710 0 0 16 2 0 0 20 0 1 0 28224110 91492352 7362 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913760264 140426840676252 0 134217728 4096 0 0 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 22337 7362 4721 1052 0 2928 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 89348 [startup+0.300274 s] /proc/loadavg: 0.99 0.86 0.47 2/55 20715 /proc/meminfo: memFree=240676/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=96684 CPUtime=0.29 /proc/20715/stat : 20715 (aptitude) R 20714 20715 17863 34816 17863 4202496 9020 1710 0 0 26 3 0 0 20 0 2 0 28224110 99004416 7652 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913766344 140426832591448 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 24171 7652 4886 1052 0 4762 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 96684 [startup+0.700211 s] /proc/loadavg: 0.99 0.86 0.47 2/55 20715 /proc/meminfo: memFree=240676/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=100468 CPUtime=0.68 /proc/20715/stat : 20715 (aptitude) R 20714 20715 17863 34816 17863 4202496 10067 1710 0 0 64 4 0 0 20 0 2 0 28224110 102879232 8695 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913761216 140426840307688 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 25117 8695 4977 1052 0 5708 0 Current children cumulated CPU time (s) 0.68 Current children cumulated vsize (KiB) 100468 [startup+1.50023 s] /proc/loadavg: 0.99 0.86 0.47 2/57 20720 /proc/meminfo: memFree=225664/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=111916 CPUtime=1.47 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 13047 1710 0 0 143 4 0 0 20 0 2 0 28224110 114601984 11674 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 27979 11674 5067 1052 0 8570 0 [pid=20715/tid=20720] ppid=20714 vsize=111916 CPUtime=0.37 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 2887 1710 0 0 37 0 0 0 20 0 2 0 28224139 114601984 11674 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307976 140426840373021 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) 111916 [startup+3.10024 s] /proc/loadavg: 0.99 0.86 0.47 2/57 20720 /proc/meminfo: memFree=206692/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=126712 CPUtime=3.07 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 16742 1710 0 0 302 5 0 0 20 0 2 0 28224110 129753088 15369 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 31678 15369 5070 1052 0 12269 0 [pid=20715/tid=20720] ppid=20714 vsize=126712 CPUtime=1.97 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 6581 1710 0 0 196 1 0 0 20 0 2 0 28224139 129753088 15369 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307608 140426840438757 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) 126712 [startup+6.30025 s] /proc/loadavg: 0.99 0.87 0.47 2/57 20720 /proc/meminfo: memFree=177552/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=220692 CPUtime=6.25 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 23852 1710 0 0 617 8 0 0 20 0 2 0 28224110 225988608 22479 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 55173 22479 5070 1052 0 35764 0 [pid=20715/tid=20720] ppid=20714 vsize=220692 CPUtime=5.15 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 13690 1710 0 0 511 4 0 0 20 0 2 0 28224139 225988608 22479 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307256 140426839948378 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) 220692 [startup+12.7003 s] /proc/loadavg: 0.99 0.87 0.47 2/57 20720 /proc/meminfo: memFree=123116/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=272816 CPUtime=12.62 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 36859 1710 0 0 1245 17 0 0 20 0 2 0 28224110 279363584 35486 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 68204 35486 5070 1052 0 48795 0 [pid=20715/tid=20720] ppid=20714 vsize=272816 CPUtime=11.52 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 26697 1710 0 0 1139 13 0 0 20 0 2 0 28224139 279363584 35486 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307608 140426804046827 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) 272816 [startup+25.5003 s] /proc/loadavg: 0.99 0.87 0.48 2/57 20720 /proc/meminfo: memFree=27016/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=365728 CPUtime=25.36 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 60060 1710 0 0 2504 32 0 0 20 0 2 0 28224110 374505472 58687 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 91432 58687 5070 1052 0 72023 0 [pid=20715/tid=20720] ppid=20714 vsize=365728 CPUtime=24.26 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 49898 1710 0 0 2398 28 0 0 20 0 2 0 28224139 374505472 58687 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307608 140426804046840 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) 365728 [startup+51.1003 s] /proc/loadavg: 0.99 0.88 0.49 2/57 20720 /proc/meminfo: memFree=9740/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=538868 CPUtime=50.7 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 103336 1710 0 0 5013 57 0 0 20 0 2 0 28224110 551800832 101963 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 134717 101963 5071 1052 0 115308 0 [pid=20715/tid=20720] ppid=20714 vsize=538868 CPUtime=49.59 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 93174 1710 0 0 4906 53 0 0 20 0 2 0 28224139 551800832 101963 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307608 140426795247712 0 134217728 4096 0 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 50.7 Current children cumulated vsize (KiB) 538868 [startup+102.3 s] /proc/loadavg: 0.99 0.90 0.52 2/57 20720 /proc/meminfo: memFree=9532/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=866564 CPUtime=101.47 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 185157 1710 2 0 10035 112 0 0 20 0 2 0 28224110 887361536 183786 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 216641 183786 5085 1052 0 197232 0 [pid=20715/tid=20720] ppid=20714 vsize=866564 CPUtime=100.36 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 174989 1710 2 0 9928 108 0 0 20 0 2 0 28224139 887361536 183786 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307688 140426795247993 0 134217728 4096 0 0 0 0 -1 0 0 0 2 0 0 Current children cumulated CPU time (s) 101.47 Current children cumulated vsize (KiB) 866564 Maximum VSize exceeded: sending signal-name then SIGKILL [startup+147.1 s] /proc/loadavg: 1.14 0.95 0.55 2/57 20720 /proc/meminfo: memFree=9004/1022884 swapFree=0/0 [pid=20715] ppid=20714 vsize=1151560 CPUtime=145.37 /proc/20715/stat : 20715 (aptitude) S 20714 20715 17863 34816 17863 4202496 256161 1710 15 0 14374 163 0 0 20 0 2 0 28224110 1179197440 247773 18446744073709551615 140426837737472 140426842044824 140734913770752 140734913762512 140426806482507 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/20715/statm: 287890 247773 3562 1052 0 268481 0 [pid=20715/tid=20720] ppid=20714 vsize=1151560 CPUtime=144.25 /proc/20715/task/20720/stat : 20720 (aptitude) R 20714 20715 17863 34816 17863 4202560 245993 1710 15 0 14266 159 0 0 20 0 2 0 28224139 1179197440 247773 18446744073709551615 140426837737472 140426842044824 140734913770752 140426754307608 140426840564273 0 134217728 4096 0 0 0 0 -1 0 0 0 30 0 0 Current children cumulated CPU time (s) 145.37 Current children cumulated vsize (KiB) 1151560 Sending Terminated to process tree (bottom up) Sleeping 2 seconds Solver just ended. Dumping a history of the last processes samples Child ended because it received signal 15 (SIGTERM) Real time (s): 147.352 CPU time (s): 145.561 CPU user time (s): 143.857 CPU system time (s): 1.70411 CPU usage (%): 98.7849 Max. virtual memory (cumulated for all children) (KiB): 1151560 getrusage(RUSAGE_CHILDREN,...) data: user time used= 143.857 system time used= 1.70411 maximum resident set size= 992008 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 258015 page faults= 15 swaps= 0 block input operations= 528 block output operations= 16 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 370 involuntary context switches= 3988 runsolver used 0.216013 second user time and 0.48403 second system time The end