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/13.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install wmakerconf mgetty echoping apache2-common libgtkmm-2.4-1 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.97 0.89 0.53 2/55 25685 /proc/meminfo: memFree=256392/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=30144 CPUtime=0 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 769 0 0 0 0 0 0 0 20 0 1 0 28234547 30867456 668 18446744073709551615 4194304 5184042 140736052809360 140736052805544 139666784044288 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 7536 668 582 242 0 98 0 [startup+0.16647 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25685 /proc/meminfo: memFree=256392/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=34436 CPUtime=0.18 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 2088 7202 0 0 10 2 4 2 20 0 1 0 28234547 35262464 1906 18446744073709551615 4194304 5184042 140736052809360 140736052806552 139666783739343 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 8609 1906 729 242 0 1171 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 34436 [startup+0.200263 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25685 /proc/meminfo: memFree=256392/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=35228 CPUtime=0.2 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 2284 7202 0 0 12 2 4 2 20 0 1 0 28234547 36073472 2102 18446744073709551615 4194304 5184042 140736052809360 140736052806552 139666800910005 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 8807 2102 729 242 0 1369 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 35228 [startup+0.300258 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25685 /proc/meminfo: memFree=256392/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=45924 CPUtime=0.31 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 5058 7202 0 0 21 4 4 2 20 0 1 0 28234547 47026176 4868 18446744073709551615 4194304 5184042 140736052809360 140736052802968 139666783386519 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 11481 4868 835 242 0 4043 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 45924 [startup+0.700206 s] /proc/loadavg: 0.97 0.89 0.53 2/55 25685 /proc/meminfo: memFree=256392/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=59216 CPUtime=0.71 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 8407 7202 0 0 60 5 4 2 20 0 1 0 28234547 60637184 8184 18446744073709551615 4194304 5184042 140736052809360 140736052806184 139666800028405 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 14804 8184 842 242 0 7366 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 59216 [startup+1.5002 s] /proc/loadavg: 0.98 0.90 0.54 2/56 25705 /proc/meminfo: memFree=225756/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=61596 CPUtime=1.5 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 9112 7202 0 0 139 5 4 2 20 0 1 0 28234547 63074304 8695 18446744073709551615 4194304 5184042 140736052809360 140736052806664 139666800100979 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 15399 8695 842 242 0 7961 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 61596 [startup+3.1002 s] /proc/loadavg: 0.98 0.90 0.54 2/56 25705 /proc/meminfo: memFree=223028/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=67740 CPUtime=3.09 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 10932 7202 0 0 296 7 4 2 20 0 1 0 28234547 69365760 10258 18446744073709551615 4194304 5184042 140736052809360 140736052802728 139666800017897 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 16935 10258 842 242 0 9497 0 Current children cumulated CPU time (s) 3.09 Current children cumulated vsize (KiB) 67740 Solver just ended. Dumping a history of the last processes samples [startup+3.20026 s] /proc/loadavg: 0.98 0.90 0.54 2/56 25705 /proc/meminfo: memFree=223028/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=65576 CPUtime=3.19 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 10948 7202 0 0 306 7 4 2 20 0 1 0 28234547 67149824 9765 18446744073709551615 4194304 5184042 140736052809360 140736052806600 139666800191509 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 16394 9765 842 242 0 8956 0 Current children cumulated CPU time (s) 3.19 Current children cumulated vsize (KiB) 65576 [startup+3.60019 s] /proc/loadavg: 0.98 0.90 0.54 2/56 25705 /proc/meminfo: memFree=220176/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=68560 CPUtime=3.59 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 11743 7202 0 0 345 8 4 2 20 0 1 0 28234547 70205440 10047 18446744073709551615 4194304 5184042 140736052809360 140736052803624 139666800647728 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 17140 10047 842 242 0 9702 0 Current children cumulated CPU time (s) 3.59 Current children cumulated vsize (KiB) 68560 [startup+4.0002 s] /proc/loadavg: 0.98 0.90 0.54 2/56 25705 /proc/meminfo: memFree=220176/1022884 swapFree=0/0 [pid=25685] ppid=25684 vsize=63264 CPUtime=3.99 /proc/25685/stat : 25685 (cupt) R 25684 25685 17872 34816 17872 4202496 12640 7202 0 0 384 9 4 2 20 0 1 0 28234547 64782336 9238 18446744073709551615 4194304 5184042 140736052809360 140736052808808 139666783690160 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/25685/statm: 15816 9238 853 242 0 8378 0 Current children cumulated CPU time (s) 3.99 Current children cumulated vsize (KiB) 63264 Child status: 1 Real time (s): 4.01807 CPU time (s): 4.03225 CPU user time (s): 3.90024 CPU system time (s): 0.132008 CPU usage (%): 100.353 Max. virtual memory (cumulated for all children) (KiB): 70900 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.90024 system time used= 0.132008 maximum resident set size= 43732 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 19862 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 77 runsolver used 0.004 second user time and 0.016001 second system time The end