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-squeeze/logs/1.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install libgnome2-gconf-perl libroy1-prof python-simpy libchipcard20 libeb7-dev 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: 0.76 0.92 0.90 2/55 29531 /proc/meminfo: memFree=279072/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=3152 CPUtime=0 /proc/29531/stat : 29531 (runsolver) R 29530 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28679273 3227648 32 18446744073709551615 134512640 134586868 4287126688 4287124736 4151309360 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.114202 s] /proc/loadavg: 0.76 0.92 0.90 2/55 29531 /proc/meminfo: memFree=279072/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=33112 CPUtime=0.13 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 1747 7214 0 0 6 1 4 2 20 0 1 0 28679273 33906688 1566 18446744073709551615 4194304 5184042 140734259020656 140734259017848 140372047492848 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 8278 1566 729 242 0 840 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 33112 [startup+0.203048 s] /proc/loadavg: 0.76 0.92 0.90 2/55 29531 /proc/meminfo: memFree=279072/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=35228 CPUtime=0.21 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 2285 7214 0 0 12 3 4 2 20 0 1 0 28679273 36073472 2103 18446744073709551615 4194304 5184042 140734259020656 140734259017848 140372047492848 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 8807 2103 729 242 0 1369 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35228 [startup+0.300267 s] /proc/loadavg: 0.76 0.92 0.90 2/55 29531 /proc/meminfo: memFree=279072/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=37588 CPUtime=0.3 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 2925 7214 0 0 20 4 4 2 20 0 1 0 28679273 38490112 2680 18446744073709551615 4194304 5184042 140734259020656 140734259017848 140372063677507 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 9397 2680 739 242 0 1959 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 37588 [startup+0.700199 s] /proc/loadavg: 0.76 0.92 0.90 2/55 29531 /proc/meminfo: memFree=279072/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=64244 CPUtime=0.7 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 9696 7214 0 0 54 10 4 2 20 0 1 0 28679273 65785856 9442 18446744073709551615 4194304 5184042 140734259020656 140734259017896 140372063491607 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 16061 9442 851 242 0 8623 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 64244 [startup+1.5002 s] /proc/loadavg: 0.76 0.92 0.90 2/56 29551 /proc/meminfo: memFree=244724/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=65328 CPUtime=1.5 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 10053 7214 0 0 133 11 4 2 20 0 1 0 28679273 66895872 9605 18446744073709551615 4194304 5184042 140734259020656 140734259018104 140372063491515 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 16332 9605 851 242 0 8894 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 65328 [startup+3.1002 s] /proc/loadavg: 0.78 0.92 0.90 2/56 29551 /proc/meminfo: memFree=243856/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=66820 CPUtime=3.09 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 10610 7214 0 0 292 11 4 2 20 0 1 0 28679273 68423680 9905 18446744073709551615 4194304 5184042 140734259020656 140734259018104 140372063491709 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 16705 9905 851 242 0 9267 0 Current children cumulated CPU time (s) 3.09 Current children cumulated vsize (KiB) 66820 Solver just ended. Dumping a history of the last processes samples [startup+3.20028 s] /proc/loadavg: 0.78 0.92 0.90 2/56 29551 /proc/meminfo: memFree=243856/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=66820 CPUtime=3.19 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 10620 7214 0 0 302 11 4 2 20 0 1 0 28679273 68423680 9915 18446744073709551615 4194304 5184042 140734259020656 140734259018104 140372063491072 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 16705 9915 851 242 0 9267 0 Current children cumulated CPU time (s) 3.19 Current children cumulated vsize (KiB) 66820 [startup+3.6002 s] /proc/loadavg: 0.78 0.92 0.90 2/56 29551 /proc/meminfo: memFree=242864/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=66968 CPUtime=3.59 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 10671 7214 0 0 342 11 4 2 20 0 1 0 28679273 68575232 9966 18446744073709551615 4194304 5184042 140734259020656 140734259017960 140372063491607 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 16742 9966 851 242 0 9304 0 Current children cumulated CPU time (s) 3.59 Current children cumulated vsize (KiB) 66968 [startup+4.0002 s] /proc/loadavg: 0.78 0.92 0.90 2/56 29551 /proc/meminfo: memFree=242864/1022884 swapFree=0/0 [pid=29531] ppid=29530 vsize=66968 CPUtime=3.99 /proc/29531/stat : 29531 (cupt) R 29530 29531 17872 34816 17872 4202496 10749 7214 0 0 382 11 4 2 20 0 1 0 28679273 68575232 10044 18446744073709551615 4194304 5184042 140734259020656 140734259014952 140372063491491 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/29531/statm: 16742 10044 851 242 0 9304 0 Current children cumulated CPU time (s) 3.99 Current children cumulated vsize (KiB) 66968 Child status: 1 Real time (s): 4.09048 CPU time (s): 4.09626 CPU user time (s): 3.95225 CPU system time (s): 0.144009 CPU usage (%): 100.141 Max. virtual memory (cumulated for all children) (KiB): 66968 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.95225 system time used= 0.144009 maximum resident set size= 40492 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 17998 page faults= 0 swaps= 0 block input operations= 0 block output operations= 328 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 53 involuntary context switches= 667 runsolver used 0 second user time and 0.020001 second system time The end