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/123.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove libxft2 libwww0 kdepasswd ksame libraw1394-5 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.00 0.99 0.91 2/55 28371 /proc/meminfo: memFree=304896/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=3152 CPUtime=0 /proc/28371/stat : 28371 (runsolver) R 28370 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28538486 3227648 33 18446744073709551615 134512640 134586868 4288173984 4288172032 4151612464 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.135072 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28371 /proc/meminfo: memFree=304896/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=33772 CPUtime=0.16 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 1910 7200 0 0 8 1 4 3 20 0 1 0 28538486 34582528 1728 18446744073709551615 4194304 5184042 140733200696064 140733200693256 140447448956848 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 8443 1728 729 242 0 1005 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 33772 [startup+0.200276 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28371 /proc/meminfo: memFree=304896/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=35360 CPUtime=0.22 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 2314 7200 0 0 12 3 4 3 20 0 1 0 28538486 36208640 2131 18446744073709551615 4194304 5184042 140733200696064 140733200693256 140447449088187 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 8840 2131 729 242 0 1402 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 35360 [startup+0.300261 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28371 /proc/meminfo: memFree=304896/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=46712 CPUtime=0.31 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 5253 7200 0 0 20 4 4 3 20 0 1 0 28538486 47833088 5061 18446744073709551615 4194304 5184042 140733200696064 140733200690552 140447449026100 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 11678 5061 835 242 0 4240 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 46712 [startup+0.7002 s] /proc/loadavg: 1.00 0.99 0.91 2/55 28371 /proc/meminfo: memFree=304896/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=59048 CPUtime=0.72 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 8422 7200 0 0 59 6 4 3 20 0 1 0 28538486 60465152 8132 18446744073709551615 4194304 5184042 140733200696064 140733200693368 140447449033102 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 14762 8132 842 242 0 7324 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 59048 [startup+1.50021 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=274260/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=61904 CPUtime=1.51 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 9435 7200 0 0 138 6 4 3 20 0 1 0 28538486 63389696 8759 18446744073709551615 4194304 5184042 140733200696064 140733200693368 140447457455725 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 15476 8759 842 242 0 8038 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 61904 [startup+3.10021 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=271780/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=67740 CPUtime=3.11 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 11277 7200 0 0 297 7 4 3 20 0 1 0 28538486 69365760 10088 18446744073709551615 4194304 5184042 140733200696064 140733200693368 140447465367165 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 16935 10088 842 242 0 9497 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 67740 [startup+6.3002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=264092/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=76056 CPUtime=6.3 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 13732 7200 0 0 614 9 4 3 20 0 1 0 28538486 77881344 11518 18446744073709551615 4194304 5184042 140733200696064 140733200693368 140447449022843 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 19014 11518 842 242 0 11576 0 Current children cumulated CPU time (s) 6.3 Current children cumulated vsize (KiB) 76056 [startup+12.7002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=256652/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=80480 CPUtime=12.67 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 15256 7200 0 0 1251 9 4 3 20 0 1 0 28538486 82411520 13042 18446744073709551615 4194304 5184042 140733200696064 140733200693368 140447465375423 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 20120 13042 842 242 0 12682 0 Current children cumulated CPU time (s) 12.67 Current children cumulated vsize (KiB) 80480 Solver just ended. Dumping a history of the last processes samples [startup+12.8003 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=256652/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=80756 CPUtime=12.77 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 15308 7200 0 0 1261 9 4 3 20 0 1 0 28538486 82694144 13094 18446744073709551615 4194304 5184042 140733200696064 140733200693368 140447465366528 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 20189 13094 842 242 0 12751 0 Current children cumulated CPU time (s) 12.77 Current children cumulated vsize (KiB) 80756 [startup+16.0002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=254296/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=81608 CPUtime=15.95 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 15715 7200 0 0 1578 10 4 3 20 0 1 0 28538486 83566592 13501 18446744073709551615 4194304 5184042 140733200696064 140733200690280 140447465313718 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 20402 13501 842 242 0 12964 0 Current children cumulated CPU time (s) 15.95 Current children cumulated vsize (KiB) 81608 [startup+16.8002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=254048/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=81608 CPUtime=16.75 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 15755 7200 0 0 1658 10 4 3 20 0 1 0 28538486 83566592 13541 18446744073709551615 4194304 5184042 140733200696064 140733200690280 140447465366688 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 20402 13541 842 242 0 12964 0 Current children cumulated CPU time (s) 16.75 Current children cumulated vsize (KiB) 81608 [startup+17.2002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=254048/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=81608 CPUtime=17.15 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 15774 7200 0 0 1698 10 4 3 20 0 1 0 28538486 83566592 13560 18446744073709551615 4194304 5184042 140733200696064 140733200690280 140447465366888 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 20402 13560 842 242 0 12964 0 Current children cumulated CPU time (s) 17.15 Current children cumulated vsize (KiB) 81608 [startup+17.4002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=254048/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=81608 CPUtime=17.35 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 15783 7200 0 0 1718 10 4 3 20 0 1 0 28538486 83566592 13569 18446744073709551615 4194304 5184042 140733200696064 140733200690280 140447449022988 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 20402 13569 842 242 0 12964 0 Current children cumulated CPU time (s) 17.35 Current children cumulated vsize (KiB) 81608 [startup+17.5002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 28391 /proc/meminfo: memFree=254048/1022884 swapFree=0/0 [pid=28371] ppid=28370 vsize=73396 CPUtime=17.45 /proc/28371/stat : 28371 (cupt) R 28370 28371 17872 34816 17872 4202496 15798 7200 0 0 1728 10 4 3 20 0 1 0 28538486 75157504 11772 18446744073709551615 4194304 5184042 140733200696064 140733200695224 140447465506071 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/28371/statm: 18349 11772 853 242 0 10911 0 Current children cumulated CPU time (s) 17.45 Current children cumulated vsize (KiB) 73396 Child status: 1 Real time (s): 17.5566 CPU time (s): 17.5171 CPU user time (s): 17.3691 CPU system time (s): 0.148009 CPU usage (%): 99.7748 Max. virtual memory (cumulated for all children) (KiB): 81608 getrusage(RUSAGE_CHILDREN,...) data: user time used= 17.3691 system time used= 0.148009 maximum resident set size= 54336 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 23018 page faults= 0 swaps= 0 block input operations= 0 block output operations= 8 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 275 runsolver used 0.028001 second user time and 0.052003 second system time The end