adding some more debugging output

BackupPC_archiveHost_s3

@@ -113,6 +113,7 @@ class SlowFile:
         else:
             # we're late; something got slow.
             self.delayfactor += 0.5
+            logger.debug('%.2f late (congestion?); setting delayfactor to %.2f' % (starttime - self.lastblocktargettime, self.delayfactor))
 
         if self.delayfactor < 1:
             self.delayfactor = 1
@@ -245,7 +246,7 @@ if secrets.gpgsymmetrickey:
     mesg += ', encrypted with secret key'
 
 logging.info(mesg)
-sys.stdout.write(mesg + '\n')
+sys.stdout.write(time.strftime('%d-%H:%M:%S') + ": " + mesg + '\n')
 sys.stdout.flush()
 
 # Prepare the pipeline
@@ -277,11 +278,13 @@ else:
 logging.info('Beginning post-processing of %i files from %s #%i' % (len(glob.glob(fileglob)), host, bkupNum))
 
 for i in sorted(glob.glob(fileglob)):
+    sending_start = time.time()
     if secrets.gpgsymmetrickey and not i.endswith('.gpg'):
         sendfile = encrypt_file(i, secrets.gpgsymmetrickey, compPath)
     else:
         # either encryption is off, or the file is already encrypted
         sendfile = i
+    encrypt_seconds = time.time() - sending_start()
 
     # create some output so backuppc doesn't time out
     sys.stdout.write("%s: Sending %s to S3...\n" % (time.strftime('%d-%H:%M:%S'), sendfile))
@@ -304,5 +307,12 @@ for i in sorted(glob.glob(fileglob)):
             log.error('Encountered S3 exception %s, retrying in %i seconds (%i/%i)' % (e, sleeptime, retry_count, max_retries))
             time.sleep(sleeptime)
 
+    size = os.path.getsize(sendfile)
+
     os.unlink(sendfile)
 
+    sending_seconds = time.time() - sending_start()
+
+    bytespersecond = size / (sending_seconds - encrypt_seconds)
+
+    sys.stdout.write('%s: File sent.  Total time %i seconds, crypto time %i seconds, transfer speed %i bytes/second.\n' % (time.strftime('%d-%H:%M:%S'), sending_seconds, encrypt_seconds, bytespersecond))