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/113.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove libjpeg-progs libwmf0.2-7 kate evolution-data-server xlibmesa-glu-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 Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 0.99 0.99 0.96 2/55 479 /proc/meminfo: memFree=338256/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=3152 CPUtime=0 /proc/479/stat : 479 (runsolver) R 478 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 29367953 3227648 33 18446744073709551615 134512640 134586868 4294172400 4294170448 4151833648 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 788 33 0 19 0 73 0 [startup+0.190492 s] /proc/loadavg: 0.99 0.99 0.96 2/55 479 /proc/meminfo: memFree=338256/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=35228 CPUtime=0.21 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 2262 7214 0 0 11 3 5 2 20 0 1 0 29367953 36073472 2079 18446744073709551615 4194304 5184042 140737063233344 140737063230536 139861555961367 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 8807 2079 729 242 0 1369 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35228 [startup+0.200272 s] /proc/loadavg: 0.99 0.99 0.96 2/55 479 /proc/meminfo: memFree=338256/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=35360 CPUtime=0.22 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 2316 7214 0 0 12 3 5 2 20 0 1 0 29367953 36208640 2133 18446744073709551615 4194304 5184042 140737063233344 140737063230536 139861564730592 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 8840 2133 729 242 0 1402 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 35360 [startup+0.300254 s] /proc/loadavg: 0.99 0.99 0.96 2/55 479 /proc/meminfo: memFree=338256/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=37852 CPUtime=0.33 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 3020 7214 0 0 20 6 5 2 20 0 1 0 29367953 38760448 2774 18446744073709551615 4194304 5184042 140737063233344 140737063230536 139861555924532 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 9463 2774 739 242 0 2025 0 Current children cumulated CPU time (s) 0.33 Current children cumulated vsize (KiB) 37852 [startup+0.700202 s] /proc/loadavg: 0.99 0.99 0.96 2/55 479 /proc/meminfo: memFree=338256/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=62252 CPUtime=0.72 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 9226 7214 0 0 54 11 5 2 20 0 1 0 29367953 63746048 8972 18446744073709551615 4194304 5184042 140737063233344 140737063230648 139861572265352 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 15563 8972 851 242 0 8125 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 62252 [startup+1.5002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 499 /proc/meminfo: memFree=301552/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=68584 CPUtime=1.52 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 10947 7214 0 0 133 12 5 2 20 0 1 0 29367953 70230016 10499 18446744073709551615 4194304 5184042 140737063233344 140737063230648 139861572264755 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 17146 10499 851 242 0 9708 0 Current children cumulated CPU time (s) 1.52 Current children cumulated vsize (KiB) 68584 [startup+3.10022 s] /proc/loadavg: 0.99 0.99 0.96 2/56 499 /proc/meminfo: memFree=297832/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=71316 CPUtime=3.11 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 11831 7214 0 0 292 12 5 2 20 0 1 0 29367953 73027584 11126 18446744073709551615 4194304 5184042 140737063233344 140737063230648 139861555921168 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 17829 11126 851 242 0 10391 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 71316 Solver just ended. Dumping a history of the last processes samples [startup+3.20028 s] /proc/loadavg: 0.99 0.99 0.96 2/56 499 /proc/meminfo: memFree=297832/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=71316 CPUtime=3.21 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 11844 7214 0 0 302 12 5 2 20 0 1 0 29367953 73027584 11139 18446744073709551615 4194304 5184042 140737063233344 140737063230648 139861572211764 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 17829 11139 851 242 0 10391 0 Current children cumulated CPU time (s) 3.21 Current children cumulated vsize (KiB) 71316 [startup+4.8002 s] /proc/loadavg: 0.99 0.99 0.96 2/56 499 /proc/meminfo: memFree=295476/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=75032 CPUtime=4.8 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 12988 7214 0 0 460 13 5 2 20 0 1 0 29367953 76832768 11770 18446744073709551615 4194304 5184042 140737063233344 140737063230648 139861555921278 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 18758 11770 851 242 0 11320 0 Current children cumulated CPU time (s) 4.8 Current children cumulated vsize (KiB) 75032 [startup+5.60715 s] /proc/loadavg: 0.99 0.99 0.96 2/56 499 /proc/meminfo: memFree=290144/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=79536 CPUtime=5.6 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 14197 7214 0 0 539 14 5 2 20 0 1 0 29367953 81444864 12979 18446744073709551615 4194304 5184042 140737063233344 140737063230648 139861555912363 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 19884 12979 851 242 0 12446 0 Current children cumulated CPU time (s) 5.6 Current children cumulated vsize (KiB) 79536 [startup+5.80021 s] /proc/loadavg: 0.99 0.99 0.96 2/56 499 /proc/meminfo: memFree=290144/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=80472 CPUtime=5.79 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 14458 7214 0 0 558 14 5 2 20 0 1 0 29367953 82403328 13240 18446744073709551615 4194304 5184042 140737063233344 140737063230648 139861572265504 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 20118 13240 851 242 0 12680 0 Current children cumulated CPU time (s) 5.79 Current children cumulated vsize (KiB) 80472 [startup+5.90021 s] /proc/loadavg: 0.99 0.99 0.96 2/56 499 /proc/meminfo: memFree=290144/1022884 swapFree=0/0 [pid=479] ppid=478 vsize=75864 CPUtime=5.89 /proc/479/stat : 479 (cupt) R 478 479 17872 34816 17872 4202496 14471 7214 0 0 568 14 5 2 20 0 1 0 29367953 77684736 12390 18446744073709551615 4194304 5184042 140737063233344 140737063232792 139861555912310 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/479/statm: 18966 12390 862 242 0 11528 0 Current children cumulated CPU time (s) 5.89 Current children cumulated vsize (KiB) 75864 Child status: 1 Real time (s): 5.9449 CPU time (s): 5.95237 CPU user time (s): 5.77236 CPU system time (s): 0.180011 CPU usage (%): 100.126 Max. virtual memory (cumulated for all children) (KiB): 80472 getrusage(RUSAGE_CHILDREN,...) data: user time used= 5.77236 system time used= 0.180011 maximum resident set size= 53012 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 21705 page faults= 0 swaps= 0 block input operations= 0 block output operations= 48 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 107 runsolver used 0.020001 second user time and 0.012 second system time The end