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/49.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install pathogen contact-lookup-applet libdbd-pg-perl exim gnusound 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.97 0.82 2/55 26487 /proc/meminfo: memFree=309224/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=30148 CPUtime=0 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 790 0 0 0 0 0 0 0 20 0 1 0 28343314 30871552 689 18446744073709551615 4194304 5184042 140735653161344 140735653159352 4777440 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 7537 689 597 242 0 99 0 [startup+0.118652 s] /proc/loadavg: 0.99 0.97 0.82 2/55 26487 /proc/meminfo: memFree=309224/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=33376 CPUtime=0.13 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 1808 7220 0 0 4 3 4 2 20 0 1 0 28343314 34177024 1626 18446744073709551615 4194304 5184042 140735653161344 140735653158536 140480782425623 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 8344 1626 729 242 0 906 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 33376 [startup+0.200266 s] /proc/loadavg: 0.99 0.97 0.82 2/55 26487 /proc/meminfo: memFree=309224/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=35492 CPUtime=0.21 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 2331 7220 0 0 11 4 4 2 20 0 1 0 28343314 36343808 2148 18446744073709551615 4194304 5184042 140735653161344 140735653158536 140480798915552 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 8873 2148 729 242 0 1435 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35492 [startup+0.300258 s] /proc/loadavg: 0.99 0.97 0.82 2/55 26487 /proc/meminfo: memFree=309224/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=47160 CPUtime=0.31 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 5353 7220 0 0 18 7 4 2 20 0 1 0 28343314 48291840 5162 18446744073709551615 4194304 5184042 140735653161344 140735653155832 140480799594351 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 11790 5162 835 242 0 4352 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 47160 [startup+0.700204 s] /proc/loadavg: 0.99 0.97 0.82 2/55 26487 /proc/meminfo: memFree=309224/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=59296 CPUtime=0.71 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 8442 7220 0 0 56 9 4 2 20 0 1 0 28343314 60719104 8218 18446744073709551615 4194304 5184042 140735653161344 140735653158648 140480791198189 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 14824 8218 842 242 0 7386 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 59296 [startup+1.5002 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=278844/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=60668 CPUtime=1.51 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 8886 7220 0 0 136 9 4 2 20 0 1 0 28343314 62124032 8468 18446744073709551615 4194304 5184042 140735653161344 140735653158776 140480782380812 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 15167 8468 842 242 0 7729 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 60668 [startup+3.10021 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=277728/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=61692 CPUtime=3.11 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 9380 7220 0 0 296 9 4 2 20 0 1 0 28343314 63172608 8705 18446744073709551615 4194304 5184042 140735653161344 140735653158792 140480798714686 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 15423 8705 842 242 0 7985 0 Current children cumulated CPU time (s) 3.11 Current children cumulated vsize (KiB) 61692 [startup+6.30021 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=270908/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=68820 CPUtime=6.28 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 11711 7220 0 0 612 10 4 2 20 0 1 0 28343314 70471680 10523 18446744073709551615 4194304 5184042 140735653161344 140735653154760 140480782381848 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 17205 10523 842 242 0 9767 0 Current children cumulated CPU time (s) 6.28 Current children cumulated vsize (KiB) 68820 [startup+12.7002 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=253052/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=87168 CPUtime=12.66 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 17103 7220 0 0 1249 11 4 2 20 0 1 0 28343314 89260032 14890 18446744073709551615 4194304 5184042 140735653161344 140735653155640 140480798729635 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 21792 14890 842 242 0 14354 0 Current children cumulated CPU time (s) 12.66 Current children cumulated vsize (KiB) 87168 Solver just ended. Dumping a history of the last processes samples [startup+12.8003 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=253052/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=87168 CPUtime=12.76 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 17115 7220 0 0 1259 11 4 2 20 0 1 0 28343314 89260032 14902 18446744073709551615 4194304 5184042 140735653161344 140735653155640 140480798812256 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 21792 14902 842 242 0 14354 0 Current children cumulated CPU time (s) 12.76 Current children cumulated vsize (KiB) 87168 [startup+13.6002 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=252556/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=87168 CPUtime=13.55 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 17207 7220 0 0 1338 11 4 2 20 0 1 0 28343314 89260032 14994 18446744073709551615 4194304 5184042 140735653161344 140735653155640 140480782376619 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 21792 14994 842 242 0 14354 0 Current children cumulated CPU time (s) 13.55 Current children cumulated vsize (KiB) 87168 [startup+14.4071 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=252060/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=87168 CPUtime=14.35 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202496 17299 7220 0 0 1418 11 4 2 20 0 1 0 28343314 89260032 15086 18446744073709551615 4194304 5184042 140735653161344 140735653155640 140480782385676 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 21792 15086 842 242 0 14354 0 Current children cumulated CPU time (s) 14.35 Current children cumulated vsize (KiB) 87168 [startup+14.6002 s] /proc/loadavg: 0.99 0.97 0.82 2/56 26507 /proc/meminfo: memFree=252060/1022884 swapFree=0/0 [pid=26487] ppid=26486 vsize=0 CPUtime=14.55 /proc/26487/stat : 26487 (cupt) R 26486 26487 17872 34816 17872 4202500 17340 7220 0 0 1436 13 4 2 20 0 1 0 28343314 0 0 18446744073709551615 0 0 0 0 0 0 0 0 0 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/26487/statm: 0 0 0 0 0 0 0 Current children cumulated CPU time (s) 14.55 Current children cumulated vsize (KiB) 0 Child status: 1 Real time (s): 14.6003 CPU time (s): 14.5689 CPU user time (s): 14.4129 CPU system time (s): 0.156009 CPU usage (%): 99.7849 Max. virtual memory (cumulated for all children) (KiB): 87168 getrusage(RUSAGE_CHILDREN,...) data: user time used= 14.4129 system time used= 0.156009 maximum resident set size= 60428 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 24560 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= 250 runsolver used 0.016001 second user time and 0.052003 second system time The end