"Fossies" - the Fresh Open Source Software Archive

Member "Tardis-1.2.1/src/Tardis/Client.py" (9 Jun 2021, 100353 Bytes) of package /linux/privat/Tardis-1.2.1.tar.gz:


As a special service "Fossies" has tried to format the requested source page into HTML format using (guessed) Python source code syntax highlighting (style: standard) with prefixed line numbers. Alternatively you can here view or download the uninterpreted source code file. For more information about "Client.py" see the Fossies "Dox" file reference documentation and the latest Fossies "Diffs" side-by-side code changes report: 1.1.5_vs_1.2.1.

    1 # vi: set et sw=4 sts=4 fileencoding=utf-8:
    2 #
    3 # Tardis: A Backup System
    4 # Copyright 2013-2020, Eric Koldinger, All Rights Reserved.
    5 # kolding@washington.edu
    6 #
    7 # Redistribution and use in source and binary forms, with or without
    8 # modification, are permitted provided that the following conditions are met:
    9 #
   10 #     * Redistributions of source code must retain the above copyright
   11 #       notice, this list of conditions and the following disclaimer.
   12 #     * Redistributions in binary form must reproduce the above copyright
   13 #       notice, this list of conditions and the following disclaimer in the
   14 #       documentation and/or other materials provided with the distribution.
   15 #     * Neither the name of the copyright holder nor the
   16 #       names of its contributors may be used to endorse or promote products
   17 #       derived from this software without specific prior written permission.
   18 #
   19 # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
   20 # AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
   21 # IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
   22 # ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE
   23 # LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
   24 # CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
   25 # SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
   26 # INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
   27 # CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
   28 # ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
   29 # POSSIBILITY OF SUCH DAMAGE.
   30 
   31 import os
   32 import sys
   33 import os.path
   34 import signal
   35 import logging
   36 import logging.handlers
   37 import fnmatch
   38 import re
   39 import glob
   40 import itertools
   41 import json
   42 import argparse
   43 import configparser
   44 import time
   45 import datetime
   46 import base64
   47 import subprocess
   48 import hashlib
   49 import tempfile
   50 import io
   51 import shlex
   52 import urllib.parse
   53 import functools
   54 import stat
   55 import uuid
   56 import errno
   57 import unicodedata
   58 import pprint
   59 import traceback
   60 import threading
   61 import cProfile
   62 import socket
   63 import concurrent.futures
   64 
   65 from binascii import hexlify
   66 
   67 import magic
   68 import pid
   69 import parsedatetime
   70 import srp
   71 import colorlog
   72 from pathmatch import wildmatch
   73 from functools import reduce
   74 from collections import defaultdict
   75 
   76 import Tardis
   77 import Tardis.TardisCrypto as TardisCrypto
   78 import Tardis.CompressedBuffer as CompressedBuffer
   79 import Tardis.Connection as Connection
   80 import Tardis.Util as Util
   81 import Tardis.Defaults as Defaults
   82 import Tardis.librsync as librsync
   83 import Tardis.MultiFormatter as MultiFormatter
   84 import Tardis.StatusBar as StatusBar
   85 import Tardis.Backend as Backend
   86 #import Tardis.Throttler as Throttler
   87 import Tardis.ThreadedScheduler as ThreadedScheduler
   88 
   89 features = Tardis.check_features()
   90 support_xattr = 'xattr' in features
   91 support_acl   = 'pylibacl' in features
   92 
   93 if support_xattr:
   94     import xattr
   95 if support_acl:
   96     import posix1e
   97 
   98 globalExcludeFile   = Defaults.getDefault('TARDIS_GLOBAL_EXCLUDES')
   99 
  100 local_config = Defaults.getDefault('TARDIS_LOCAL_CONFIG')
  101 if not os.path.exists(local_config):
  102     local_config = Defaults.getDefault('TARDIS_DAEMON_CONFIG')
  103 
  104 configDefaults = {
  105     # Remote Socket connectionk params
  106     'Server':               Defaults.getDefault('TARDIS_SERVER'),
  107     'Port':                 Defaults.getDefault('TARDIS_PORT'),
  108 
  109     # Local Direct connect params
  110     'BaseDir':              Defaults.getDefault('TARDIS_DB'),
  111     'DBDir':                Defaults.getDefault('TARDIS_DBDIR'),
  112     'DBName':               Defaults.getDefault('TARDIS_DBNAME'),
  113     'Schema':               Defaults.getDefault('TARDIS_SCHEMA'),
  114 
  115     'Local':                '',
  116 
  117     'Client':               Defaults.getDefault('TARDIS_CLIENT'),
  118     'Force':                str(False),
  119     'Full':                 str(False),
  120     'Timeout':              str(300.0),
  121     'Password':             None,
  122     'PasswordFile':         Defaults.getDefault('TARDIS_PWFILE'),
  123     'PasswordProg':         None,
  124     'Crypt':                str(True),
  125     'KeyFile':              Defaults.getDefault('TARDIS_KEYFILE'),
  126     'SendClientConfig':     Defaults.getDefault('TARDIS_SEND_CONFIG'),
  127     'CompressData':         'none',
  128     'CompressMin':          str(4096),
  129     'NoCompressFile':       Defaults.getDefault('TARDIS_NOCOMPRESS'),
  130     'NoCompress':           '',
  131     'CompressMsgs':         'none',
  132     'Purge':                str(False),
  133     'IgnoreCVS':            str(False),
  134     'SkipCaches':           str(False),
  135     'SendSig':              str(False),
  136     'ExcludePatterns':      '',
  137     'ExcludeDirs':          '',
  138     'GlobalExcludeFileName':Defaults.getDefault('TARDIS_GLOBAL_EXCLUDES'),
  139     'ExcludeFileName':      Defaults.getDefault('TARDIS_EXCLUDES'),
  140     'LocalExcludeFileName': Defaults.getDefault('TARDIS_LOCAL_EXCLUDES'),
  141     'SkipFileName':         Defaults.getDefault('TARDIS_SKIP'),
  142     'ExcludeNoAccess':      str(True),
  143     'LogFiles':             '',
  144     'Verbosity':            str(0),
  145     'Stats':                str(False),
  146     'Report':               'none',
  147     'Directories':          '.',
  148     
  149     # Backend parameters
  150     'Formats'               : 'Monthly-%Y-%m, Weekly-%Y-%U, Daily-%Y-%m-%d',
  151     'Priorities'            : '40, 30, 20',
  152     'KeepDays'              : '0, 180, 30',
  153     'ForceFull'             : '0, 0, 0',
  154     'Umask'                 : '027',
  155     'User'                  : '',
  156     'Group'                 : '',
  157     'CksContent'            : '65536',
  158     'AutoPurge'             : str(False),
  159     'SaveConfig'            : str(True),
  160     'AllowClientOverrides'  : str(True),
  161     'AllowSchemaUpgrades'   : str(False),
  162     'JournalFile'           : Defaults.getDefault('TARDIS_JOURNAL'),
  163     'SaveFull'              : str(False),
  164     'MaxDeltaChain'         : '5',
  165     'MaxChangePercent'      : '50',
  166     'DBBackups'             : '0',
  167     'LinkBasis'             : str(False),
  168     'RequirePassword'       : str(False),
  169 }
  170 
  171 excludeDirs         = []
  172 
  173 starttime           = None
  174 
  175 encoding            = None
  176 encoder             = None
  177 decoder             = None
  178 
  179 purgePriority       = None
  180 purgeTime           = None
  181 
  182 globalExcludes      = set()
  183 cvsExcludes         = ["RCS", "SCCS", "CVS", "CVS.adm", "RCSLOG", "cvslog.*", "tags", "TAGS", ".make.state", ".nse_depinfo",
  184                        "*~", "#*", ".#*", ",*", "_$*", "*$", "*.old", "*.bak", "*.BAK", "*.orig", "*.rej", ".del-*", "*.a",
  185                        "*.olb", "*.o", "*.obj", "*.so", "*.exe", "*.Z", "*.elc", "*.ln", "core", ".*.swp", ".*.swo",
  186                        ".svn", ".git", ".hg", ".bzr"]
  187 verbosity           = 0
  188 
  189 conn                = None
  190 args                = None
  191 config              = None
  192 
  193 cloneDirs           = []
  194 cloneContents       = {}
  195 batchMsgs           = []
  196 metaCache           = Util.bidict()                 # A cache of metadata.  Since many files can have the same metadata, we check that
  197                                                     # that we haven't sent it yet.
  198 newmeta             = []                            # When we encounter new metadata, keep it here until we flush it to the server.
  199 
  200 noCompTypes         = []
  201 
  202 crypt               = None
  203 logger              = None
  204 exceptionLogger     = None
  205 
  206 srpUsr              = None
  207 
  208 sessionid           = None
  209 clientId            = None
  210 lastTimestamp       = None
  211 backupName          = None
  212 newBackup           = None
  213 filenameKey         = None
  214 contentKey          = None
  215 
  216 # Stats block.
  217 # dirs/files/links  == Number of directories/files/links backed up total
  218 # new/delta         == Number of new/delta files sent
  219 # backed            == Total size of data represented by the backup.
  220 # dataSent          == Number of data bytes sent this run (not including messages)
  221 # dataBacked        == Number of bytes backed up this run
  222 # Example: If you have 100 files, and 99 of them are already backed up (ie, one new), backed would be 100, but new would be 1.
  223 # dataSent is the compressed and encrypted size of the files (or deltas) sent in this run, but dataBacked is the total size of
  224 # the files.
  225 stats = { 'dirs' : 0, 'files' : 0, 'links' : 0, 'backed' : 0, 'dataSent': 0, 'dataBacked': 0 , 'new': 0, 'delta': 0, 'gone': 0, 'denied': 0 }
  226 
  227 report = {}
  228 
  229 
  230 
  231 class InodeEntry:
  232     def __init__(self):
  233         self.paths = []
  234         self.numEntries = 0
  235         self.finfo = None
  236 
  237 class InodeDB:
  238     def __init__(self):
  239         self.db = defaultdict(InodeEntry)
  240 
  241     def insert(self, inode, finfo, path):
  242         entry = self.db[inode]
  243         entry.numEntries += 1
  244         entry.paths.append(path)
  245         entry.finfo = finfo
  246 
  247     def get(self, inode, num=0):
  248         if not inode in self.db:
  249             return (None, None)
  250         entry = self.db[inode]
  251         if num >= len(entry.paths):
  252             return (entry.finfo, None)
  253         return (entry.finfo, entry.paths[num])
  254 
  255     def delete(self, inode, path=None):
  256         if inode in self.db:
  257             entry = self.db[inode]
  258             entry.numEntries -= 1
  259             if entry.numEntries == 0:
  260                 self.db.pop(inode)
  261             if path:
  262                 entry.paths.remove(path)
  263             else:
  264                 entry.paths.pop(0)
  265 
  266 inodeDB             = InodeDB()
  267 dirHashes           = {}
  268 
  269 # Logging Formatter that allows us to specify formats that won't have a levelname header, ie, those that
  270 # will only have a message
  271 class MessageOnlyFormatter(logging.Formatter):
  272     def __init__(self, fmt = '%(levelname)s: %(message)s', levels=[logging.INFO]):
  273         logging.Formatter.__init__(self, fmt)
  274         self.levels = levels
  275 
  276     def format(self, record):
  277         if record.levelno in self.levels:
  278             return record.getMessage()
  279         return logging.Formatter.format(self, record)
  280 
  281 # A custom argument parser to nicely handle argument files, and strip out any blank lines
  282 # or commented lines
  283 class CustomArgumentParser(argparse.ArgumentParser):
  284     def __init__(self, *args, **kwargs):
  285         super(CustomArgumentParser, self).__init__(*args, **kwargs)
  286 
  287     def convert_arg_line_to_args(self, line):
  288         for arg in line.split():
  289             if not arg.strip():
  290                 continue
  291             if arg[0] == '#':
  292                 break
  293             yield arg
  294 
  295 class ShortPathStatusBar(StatusBar.StatusBar):
  296     def processTrailer(self, width, name):
  297         return Util.shortPath(name, width)
  298 
  299 
  300 class ProtocolError(Exception):
  301     pass
  302 
  303 class AuthenticationFailed(Exception):
  304     pass
  305 
  306 class ExitRecursionException(Exception):
  307     def __init__(self, rootException):
  308         self.rootException = rootException
  309 
  310 class FakeDirEntry:
  311     def __init__(self, dirname, filename):
  312         self.name = filename
  313         self.path = os.path.join(dirname, filename)
  314 
  315     def stat(self, follow_symlinks=True):
  316         if follow_symlinks:
  317             return os.stat(self.path)
  318         else:
  319             return os.lstat(self.path)
  320 
  321 def setEncoder(format):
  322     global encoder, encoding, decoder
  323     if format == 'base64':
  324         encoding = "base64"
  325         encoder  = base64.b64encode
  326         decoder  = base64.b64decode
  327     elif format == 'bin':
  328         encoding = "bin"
  329         encoder = lambda x: x
  330         decoder = lambda x: x
  331 
  332 systemencoding      = sys.getfilesystemencoding()
  333 
  334 def fs_encode(val):
  335     """ Turn filenames into str's (ie, series of bytes) rather than Unicode things """
  336     if not isinstance(val, bytes):
  337         #return val.encode(sys.getfilesystemencoding())
  338         return val.encode(systemencoding)
  339     else:
  340         return val
  341 
  342 def checkMessage(message, expected):
  343     """ Check that a message is of the expected type.  Throw an exception if not """
  344     if not message['message'] == expected:
  345         logger.critical("Expected {} message, received {}".format(expected, message['message']))
  346         raise ProtocolError("Expected {} message, received {}".format(expected, message['message']))
  347 
  348 def filelist(dirname, excludes):
  349     """ List the files in a directory, except those that match something in a set of patterns """
  350     files = os.scandir(dirname)
  351     for f in files:
  352         if all(not p.match(f.path) for p in excludes):
  353             yield f
  354 
  355 #_deletedInodes = {}
  356 
  357 def msgInfo(resp=None, batch=None):
  358     if resp is None: resp = currentResponse
  359     if batch is None: batch = currentBatch
  360     respId = resp['respid']
  361     respType = resp['message']
  362     if batch:
  363         batchId = batch['respid']
  364     else:
  365         batchId = None
  366     return (respId, respType, batchId)
  367 
  368 
  369 pool = concurrent.futures.ThreadPoolExecutor()
  370 
  371 def genChecksum(inode):
  372     checksum = None
  373     try:
  374         (_, pathname) = inodeDB.get(inode)
  375         setProgress("File [C]:", pathname)
  376 
  377         m = crypt.getHash()
  378         s = os.lstat(pathname)
  379         mode = s.st_mode
  380         if stat.S_ISLNK(mode):
  381             m.update(fs_encode(os.readlink(pathname)))
  382         else:
  383             try:
  384                 with open(pathname, "rb") as f:
  385                     for chunk in iter(functools.partial(f.read, args.chunksize), b''):
  386                         if chunk:
  387                             m.update(chunk)
  388                         else:
  389                             break
  390                     checksum = m.hexdigest()
  391                     # files.append({ "inode": inode, "checksum": checksum })
  392             except IOError as e:
  393                 logger.error("Unable to generate checksum for %s: %s", pathname, str(e))
  394                 exceptionLogger.log(e)
  395                 # TODO: Add an error response?
  396     except KeyError as e:
  397         (rId, rType, bId) = msgInfo()
  398         logger.error("Unable to process checksum for %s, not found in inodeDB (%s, %s -- %s)", str(inode), rId, rType, bId)
  399         exceptionLogger.log(e)
  400     except FileNotFoundError as e:
  401         logger.error("Unable to stat %s.  File not found", pathname)
  402         exceptionLogger.log(e)
  403         # TODO: Add an error response?
  404 
  405     return inode, checksum
  406 
  407 def processChecksums(inodes):
  408     """ Generate checksums for requested checksum files """
  409     files = []
  410     jobs = pool.map(genChecksum, inodes)
  411     for job in jobs:
  412         inode, checksum = job
  413         files.append({ "inode": inode, "checksum": checksum })
  414     message = {
  415         "message": "CKS",
  416         "files": files
  417     }
  418 
  419     #response = sendAndReceive(message)
  420     #handleAckSum(response)
  421     batchMessage(message)
  422 
  423 def logFileInfo(i, c):
  424     (x, name) = inodeDB.get(i)
  425     if name:
  426         if "size" in x:
  427             size = x["size"]
  428         else:
  429             size = 0
  430         size = Util.fmtSize(size, formats=['','KB','MB','GB', 'TB', 'PB'])
  431         logger.log(logging.FILES, "[%c]: %s (%s)", c, Util.shortPath(name), size)
  432         cname = crypt.encryptPath(name)
  433         logger.debug("Filename: %s => %s", Util.shortPath(name), Util.shortPath(cname))
  434 
  435 def handleAckSum(response):
  436     checkMessage(response, 'ACKSUM')
  437     logfiles = logger.isEnabledFor(logging.FILES)
  438 
  439     done    = response.setdefault('done', {})
  440     content = response.setdefault('content', {})
  441     delta   = response.setdefault('delta', {})
  442 
  443     # First, delete all the files which are "done", ie, matched
  444     for i in [tuple(x) for x in done]:
  445         if logfiles:
  446             (x, name) = inodeDB.get(i)
  447             if name:
  448                 logger.log(logging.FILES, "[C]: %s", Util.shortPath(name))
  449         inodeDB.delete(i)
  450 
  451     # First, then send content for any files which don't
  452     # FIXME: TODO: There should be a test in here for Delta's
  453     for i in [tuple(x) for x in content]:
  454         if logfiles:
  455             logFileInfo(i, 'n')
  456         sendContent(i, 'Full')
  457         inodeDB.delete(i)
  458 
  459     signatures = None
  460     if not args.full and len(delta) != 0:
  461         signatures = prefetchSigFiles(delta)
  462 
  463     for i in [tuple(x) for x in delta]:
  464         if logfiles:
  465             logFileInfo(i, 'd')
  466         processDelta(i, signatures)
  467         inodeDB.delete(i)
  468 
  469 def makeEncryptor():
  470     iv = crypt.getIV()
  471     encryptor = crypt.getContentEncryptor(iv)
  472     return (encryptor, iv)
  473 
  474 def prefetchSigFiles(inodes):
  475     logger.debug("Requesting signature files: %s", str(inodes))
  476     signatures = {}
  477 
  478     message = {
  479         "message": "SGS",
  480         "inodes": inodes
  481     }
  482     setMessageID(message)
  483 
  484     sigmessage = sendAndReceive(message)
  485     checkMessage(sigmessage, "SIG")
  486 
  487     while sigmessage['status'] == 'OK':
  488         inode = tuple(sigmessage['inode'])
  489         logger.debug("Receiving signature for %s: Chksum: %s", str(inode), sigmessage['checksum'])
  490 
  491         sigfile = tempfile.SpooledTemporaryFile(max_size=1024 * 1024)
  492         #sigfile = cStringIO.StringIO(conn.decode(sigmessage['signature']))
  493         Util.receiveData(conn.sender, sigfile)
  494         logger.debug("Received sig file: %d", sigfile.tell())
  495         sigfile.seek(0)
  496         signatures[inode] = (sigfile, sigmessage['checksum'])
  497 
  498         # Get the next file in the stream
  499         sigmessage = receiveMessage()
  500         checkMessage(sigmessage, "SIG")
  501     return signatures
  502 
  503 def fetchSignature(inode):
  504     logger.debug("Requesting checksum for %s", str(inode))
  505     message = {
  506         "message" : "SGR",
  507         "inode" : inode
  508     }
  509     setMessageID(message)
  510 
  511     ## TODO: Comparmentalize this better.  Should be able to handle the SIG response
  512     ## Separately from the SGR.  Just needs some thinking.  SIG implies immediate
  513     ## Follow on by more data, which is unique
  514     sigmessage = sendAndReceive(message)
  515     checkMessage(sigmessage, "SIG")
  516 
  517     if sigmessage['status'] == 'OK':
  518         sigfile = io.StringIO()
  519         #sigfile = cStringIO.StringIO(conn.decode(sigmessage['signature']))
  520         Util.receiveData(conn.sender, sigfile)
  521         logger.debug("Received sig file: %d", sigfile.tell())
  522         sigfile.seek(0)
  523         checksum = sigmessage['checksum']
  524     else:
  525         (_, pathname) = inodeDB[inode]
  526         logger.warning("No signature file received for %s: %s", inode, pathname)
  527         sigfile = None
  528         checksum = None
  529 
  530     return (sigfile, None)
  531 
  532 
  533 def getInodeDBName(inode):
  534     (_, name) = inodeDB.get(inode)
  535     if name:
  536         return name
  537     else:
  538         return "Unknown"
  539 
  540 def processDelta(inode, signatures):
  541     """ Generate a delta and send it """
  542     if verbosity > 3:
  543         logger.debug("ProcessDelta: %s %s", inode, getInodeDBName(inode))
  544     if args.loginodes:
  545         args.loginodes.write(f"ProcessDelta {str(inode)} {getInodeDBName(inode)}\n".encode('utf8'))
  546 
  547     try:
  548         (_, pathname) = inodeDB.get(inode)
  549         setProgress("File [D]:", pathname)
  550         logger.debug("Processing delta: %s :: %s", str(inode), pathname)
  551 
  552         if signatures and inode in signatures:
  553             (sigfile, oldchksum) = signatures[inode]
  554         else:
  555             (sigfile, oldchksum) = fetchSignature(inode)
  556 
  557         if sigfile is not None:
  558             try:
  559                 newsig = None
  560                 # If we're encrypted, we need to generate a new signature, and send it along
  561                 makeSig = crypt.encrypting() or args.signature
  562 
  563                 logger.debug("Generating delta for %s", pathname)
  564 
  565                 # Create a buffered reader object, which can generate the checksum and an actual filesize while
  566                 # reading the file.  And, if we need it, the signature
  567                 reader = CompressedBuffer.BufferedReader(open(pathname, "rb"), hasher=crypt.getHash(), signature=makeSig)
  568                 # HACK: Monkeypatch the reader object to have a seek function to keep librsync happy.  Never gets called
  569                 reader.seek = lambda x, y: 0
  570 
  571                 # Generate the delta file
  572                 delta = librsync.delta(reader, sigfile)
  573                 sigfile.close()
  574 
  575                 # get the auxiliary info
  576                 checksum = reader.checksum()
  577                 filesize = reader.size()
  578                 newsig = reader.signatureFile()
  579 
  580                 # Figure out the size of the delta file.  Seek to the end, do a tell, and go back to the start
  581                 # Ugly.
  582                 delta.seek(0, 2)
  583                 deltasize = delta.tell()
  584                 delta.seek(0)
  585             except Exception as e:
  586                 logger.warning("Unable to process signature.  Sending full file: %s: %s", pathname, str(e))
  587                 exceptionLogger.log(e)
  588                 sendContent(inode, 'Full')
  589                 return
  590 
  591             if deltasize < (filesize * float(args.deltathreshold) / 100.0):
  592                 encrypt, iv, = makeEncryptor()
  593                 Util.accumulateStat(stats, 'delta')
  594                 message = {
  595                     "message": "DEL",
  596                     "inode": inode,
  597                     "size": filesize,
  598                     "checksum": checksum,
  599                     "basis": oldchksum,
  600                     "encoding": encoding,
  601                     "encrypted": True if iv else False
  602                 }
  603 
  604                 sendMessage(message)
  605                 #batchMessage(message, flush=True, batch=False, response=False)
  606                 compress = args.compress if (args.compress and (filesize > args.mincompsize)) else None
  607                 (sent, _, _) = Util.sendData(conn.sender, delta, encrypt, chunksize=args.chunksize, compress=compress, stats=stats)
  608                 delta.close()
  609 
  610                 # If we have a signature, send it.
  611                 sigsize = 0
  612                 if newsig:
  613                     message = {
  614                         "message" : "SIG",
  615                         "checksum": checksum
  616                     }
  617                     sendMessage(message)
  618                     #batchMessage(message, flush=True, batch=False, response=False)
  619                     # Send the signature, generated above
  620                     (sigsize, _, _) = Util.sendData(conn.sender, newsig, TardisCrypto.NullEncryptor(), chunksize=args.chunksize, compress=False, stats=stats) # Don't bother to encrypt the signature
  621                     newsig.close()
  622 
  623                 if args.report != 'none':
  624                     x = { 'type': 'Delta', 'size': sent, 'sigsize': sigsize }
  625                     # Convert to Unicode, and normalize any characters, so lengths become reasonable
  626                     name = unicodedata.normalize('NFD', pathname)
  627                     report[os.path.split(pathname)] = x
  628                 logger.debug("Completed %s -- Checksum %s -- %s bytes, %s signature bytes", Util.shortPath(pathname), checksum, sent, sigsize)
  629             else:
  630                 if logger.isEnabledFor(logging.DEBUG):
  631                     logger.debug("Delta size for %s is too large.  Sending full content: Delta: %d File: %d", Util.shortPath(pathname, 40), deltasize, filesize)
  632                 sendContent(inode, 'Full')
  633         else:
  634             sendContent(inode, 'Full')
  635     except KeyError as e:
  636         logger.error("ProcessDelta: No inode entry for %s", inode)
  637         logger.debug(repr(traceback.format_stack()))
  638         if args.loginodes:
  639             args.loginodes.write(f"ProcessDelta No inode entry for {str(inode)}\n".encode('utf8'))
  640         exceptionLogger.log(e)
  641 
  642 def sendContent(inode, reportType):
  643     """ Send the content of a file.  Compress and encrypt, as specified by the options. """
  644 
  645     if verbosity > 3:
  646         logger.debug("SendContent: %s %s %s", inode, reportType, getInodeDBName(inode))
  647     if args.loginodes:
  648         args.loginodes.write(f"SendContent: {inode} {reportType} {getInodeDBName(inode)}\n".encode('utf8'))
  649     #if inode in inodeDB:
  650     try:
  651         checksum = None
  652         (fileInfo, pathname) = inodeDB.get(inode)
  653         if pathname:
  654             mode = fileInfo["mode"]
  655             filesize = fileInfo["size"]
  656 
  657             if logger.isEnabledFor(logging.DEBUG):
  658                 logger.debug("Sending content for %s (%s) -- %s", inode, Util.fmtSize(filesize), Util.shortPath(pathname, 60))
  659 
  660             setProgress("File [N]:", pathname)
  661 
  662             if stat.S_ISDIR(mode):
  663                 return
  664             encrypt, iv, = makeEncryptor()
  665             message = {
  666                 "message":      "CON",
  667                 "inode":        inode,
  668                 "encoding":     encoding,
  669                 "encrypted":    True if iv else False
  670             }
  671 
  672             # Attempt to open the data source
  673             # Punt out if unsuccessful
  674             try:
  675                 if stat.S_ISLNK(mode):
  676                     # It's a link.  Send the contents of readlink
  677                     data = io.BytesIO(fs_encode(os.readlink(pathname)))
  678                 else:
  679                     data = open(pathname, "rb")
  680             except IOError as e:
  681                 if e.errno == errno.ENOENT:
  682                     logger.warning("%s disappeared.  Not backed up", pathname)
  683                     Util.accumulateStat(stats, 'gone')
  684                 elif e.errno == errno.EACCES:
  685                     logger.warning("Permission denied opening: %s.  Not backed up", pathname)
  686                     Util.accumulateStat(stats, 'denied')
  687                 else:
  688                     logger.warning("Unable to open %s: %s", pathname, e.strerror)
  689                     Util.accumulateStat(stats, 'denied')
  690                 return
  691 
  692             # Attempt to send the data.
  693             sig = None
  694             sigsize = 0
  695             try:
  696                 compress = args.compress if (args.compress and (filesize > args.mincompsize)) else None
  697                 # Check if it's a file type we don't want to compress
  698                 if compress and noCompTypes:
  699                     mimeType = magic.from_buffer(data.read(128), mime=True)
  700                     data.seek(0)
  701                     if mimeType in noCompTypes:
  702                         logger.debug("Not compressing %s.  Type %s", pathname, mimeType)
  703                         compress = False
  704                 makeSig = crypt.encrypting() or args.signature
  705                 sendMessage(message)
  706                 #batchMessage(message, batch=False, flush=True, response=False)
  707                 (size, checksum, sig) = Util.sendData(conn.sender, data,
  708                                                       encrypt, hasher=crypt.getHash(),
  709                                                       chunksize=args.chunksize,
  710                                                       compress=compress,
  711                                                       signature=makeSig,
  712                                                       stats=stats)
  713 
  714                 if sig:
  715                     sig.seek(0)
  716                     message = {
  717                         "message" : "SIG",
  718                         "checksum": checksum
  719                     }
  720                     sendMessage(message)
  721                     #batchMessage(message, batch=False, flush=True, response=False)
  722                     (sigsize, _, _) = Util.sendData(conn.sender, sig, TardisCrypto.NullEncryptor(), chunksize=args.chunksize, stats=stats)            # Don't bother to encrypt the signature
  723             except Exception as e:
  724                 logger.error("Caught exception during sending of data in %s: %s", pathname, e)
  725                 exceptionLogger.log(e)
  726                 #raise e
  727             finally:
  728                 if data is not None:
  729                     data.close()
  730                 if sig is not None:
  731                     sig.close()
  732 
  733             Util.accumulateStat(stats, 'new')
  734             if args.report != 'none':
  735                 repInfo = { 'type': reportType, 'size': size, 'sigsize': sigsize }
  736                 report[os.path.split(pathname)] = repInfo
  737             logger.debug("Completed %s -- Checksum %s -- %s bytes, %s signature bytes", Util.shortPath(pathname), checksum, size, sigsize)
  738     except KeyError as e:
  739         logger.error("SendContent: No inode entry for %s", inode)
  740         logger.debug(repr(traceback.format_stack()))
  741         if args.loginodes:
  742             args.loginodes.write(f"SendContent: No inode entry for {inode}\n".encode('utf8'))
  743         exceptionLogger.log(e)
  744 
  745 def handleAckMeta(message):
  746     checkMessage(message, 'ACKMETA')
  747     content = message.setdefault('content', {})
  748     done    = message.setdefault('done', {})
  749 
  750     for cks in content:
  751         data = metaCache.inverse[cks][0]
  752         logger.debug("Sending meta data chunk: %s -- %s", cks, data)
  753 
  754         encrypt, iv = makeEncryptor()
  755         message = {
  756             "message": "METADATA",
  757             "checksum": cks,
  758             "encrypted": True if iv else False
  759         }
  760 
  761         sendMessage(message)
  762         compress = args.compress if (args.compress and (len(data) > args.mincompsize)) else None
  763         Util.sendData(conn.sender, io.BytesIO(bytes(data, 'utf8')), encrypt, chunksize=args.chunksize, compress=compress, stats=stats)
  764 
  765 _defaultHash = None
  766 def sendDirHash(inode):
  767     global _defaultHash
  768     if _defaultHash == None:
  769         _defaultHash = crypt.getHash().hexdigest()
  770 
  771     i = tuple(inode)
  772     #try:
  773     #    (h,s) = dirHashes[i]
  774     #except KeyError:
  775     #    logger.error("%s, No directory hash available for inode %d on device %d", i, i[0], i[1])
  776     (h,s) = dirHashes.setdefault(i, (_defaultHash, 0))
  777 
  778     message = {
  779         'message': 'DHSH',
  780         'inode'  : inode,
  781         'hash'   : h,
  782         'size'   : s
  783         }
  784 
  785     batchMessage(message)
  786     try:
  787         del dirHashes[i]
  788     except KeyError as e:
  789         pass
  790         # This kindof isn't an error.   The BatchMessages call can cause the sendDirHashes to be sent again, which ends up deleteing
  791         # the message before it's deleted here.
  792         #logger.warning("Unable to delete Directory Hash for %s", i)
  793         #if args.exceptions:
  794         #    logger.exception("No directory hash entry for %s", i)
  795 
  796 def cksize(i, threshhold):
  797     (f, _) = inodeDB.get(i)
  798     if f and f['size'] > threshhold:
  799         return True
  800     return False
  801 
  802 allContent = []
  803 allDelta   = []
  804 allCkSum   = []
  805 allRefresh = []
  806 allDone    = []
  807 
  808 def handleAckDir(message):
  809     global allContent, allDelta, allCkSum, allRefresh, allDone
  810 
  811     checkMessage(message, 'ACKDIR')
  812 
  813     content = message.setdefault("content", {})
  814     done    = message.setdefault("done", {})
  815     delta   = message.setdefault("delta", {})
  816     cksum   = message.setdefault("cksum", {})
  817     refresh = message.setdefault("refresh", {})
  818 
  819     if verbosity > 2:
  820         path = message['path']
  821         if crypt:
  822             path = crypt.decryptPath(path)
  823         logger.debug("Processing ACKDIR: Up-to-date: %3d New Content: %3d Delta: %3d ChkSum: %3d -- %s", len(done), len(content), len(delta), len(cksum), Util.shortPath(path, 40))
  824 
  825     if args.loginodes:
  826         args.loginodes.write(f"Adding to AllContent: ({len(allContent)}):: {len(content)}: {str(content)}\n".encode('utf8'))
  827         args.loginodes.write(f"Adding to AllRefresh: ({len(allRefresh)}):: {len(refresh)}: {str(refresh)}\n".encode('utf8'))
  828         args.loginodes.write(f"Adding to AllDelta:   ({len(allDelta)}):: {len(delta)}: {str(delta)}\n".encode('utf8'))
  829         args.loginodes.write(f"Adding to AllCkSum:   ({len(allCkSum)}):: {len(cksum)}: {str(cksum)}\n".encode('utf8'))
  830 
  831     allContent += content
  832     allDelta   += delta
  833     allCkSum   += cksum
  834     allRefresh += refresh
  835     allDone    += done
  836 
  837 def pushFiles():
  838     global allContent, allDelta, allCkSum, allRefresh, allDone
  839     logger.debug("Pushing files")
  840     # If checksum content in NOT specified, send the data for each file
  841     if args.loginodes:
  842         args.loginodes.write(f"Pushing Files\n".encode('utf8'))
  843         args.loginodes.write(f"AllContent: {len(allContent)}: {str(allContent)}\n".encode('utf8'))
  844         args.loginodes.write(f"AllRefresh: {len(allRefresh)}: {str(allRefresh)}\n".encode('utf8'))
  845         args.loginodes.write(f"AllDelta:   {len(allDelta)}: {str(allDelta)}\n".encode('utf8'))
  846         args.loginodes.write(f"AllCkSum:   {len(allCkSum)}: {str(allCkSum)}\n".encode('utf8'))
  847 
  848     processed = []
  849 
  850     for i in [tuple(x) for x in allContent]:
  851         try:
  852             if logger.isEnabledFor(logging.FILES):
  853                 logFileInfo(i, 'N')
  854             sendContent(i, 'New')
  855             processed.append(i)
  856         except Exception as e:
  857             logger.error("Unable to backup %s: %s", str(i), str(e))
  858 
  859 
  860     for i in [tuple(x) for x in allRefresh]:
  861         if logger.isEnabledFor(logging.FILES):
  862             logFileInfo(i, 'R')
  863         try:
  864             sendContent(i, 'Full')
  865             processed.append(i)
  866         except Exception as e:
  867             logger.error("Unable to backup %s: %s", str(i), str(e))
  868 
  869     # If there are any delta files requested, ask for them
  870     signatures = None
  871     if not args.full and len(allDelta) != 0:
  872         signatures = prefetchSigFiles(allDelta)
  873 
  874     for i in [tuple(x) for x in allDelta]:
  875         # If doing a full backup, send the full file, else just a delta.
  876         try:
  877             if args.full:
  878                 if logger.isEnabledFor(logging.FILES):
  879                     logFileInfo(i, 'N')
  880                 sendContent(i, 'Full')
  881             else:
  882                 if logger.isEnabledFor(logging.FILES):
  883                     (x, name) = inodeDB.get(i)
  884                     if name:
  885                         logger.log(logging.FILES, "[D]: %s", Util.shortPath(name))
  886                 processDelta(i, signatures)
  887             processed.append(i)
  888         except Exception as e:
  889             logger.error("Unable to backup %s: ", str(i), str(e))
  890 
  891     # clear it out
  892     for i in processed:
  893         inodeDB.delete(i)
  894     for i in [tuple(x) for x in allDone]:
  895         inodeDB.delete(i)
  896     allRefresh = []
  897     allContent = []
  898     allDelta   = []
  899     allDone    = []
  900 
  901     # If checksum content is specified, concatenate the checksums and content requests, and handle checksums
  902     # for all of them.
  903     if len(allCkSum) > 0:
  904         cksums = [tuple(x) for x in allCkSum]
  905         allCkSum   = []             # Clear it out to avoid processing loop
  906         processChecksums(cksums)
  907 
  908 
  909     logger.debug("Done pushing")
  910 
  911     #if message['last']:
  912     #    sendDirHash(message['inode'])
  913 
  914 def addMeta(meta):
  915     """
  916     Add data to the metadata cache
  917     """
  918     if meta in metaCache:
  919         return metaCache[meta]
  920     else:
  921         m = crypt.getHash()
  922         m.update(bytes(meta, 'utf8'))
  923         digest = m.hexdigest()
  924         metaCache[meta] = digest
  925         newmeta.append(digest)
  926         return digest
  927 
  928 def mkFileInfo(f):
  929     pathname = f.path
  930     s = f.stat(follow_symlinks=False)
  931 
  932     # Cleanup any bogus characters
  933     name = f.name.encode('utf8', 'backslashreplace').decode('utf8')
  934 
  935     mode = s.st_mode
  936 
  937     # If we don't want to even create dir entries for things we can't access, just return None 
  938     # if we can't access the file itself
  939     if args.skipNoAccess and (not Util.checkPermission(s.st_uid, s.st_gid, mode)):
  940         return None
  941 
  942     if stat.S_ISREG(mode) or stat.S_ISDIR(mode) or stat.S_ISLNK(mode):
  943         #name = crypt.encryptFilename(name)
  944         finfo =  {
  945             'name':   name,
  946             'inode':  s.st_ino,
  947             'dir':    stat.S_ISDIR(mode),
  948             'link':   stat.S_ISLNK(mode),
  949             'nlinks': s.st_nlink,
  950             'size':   s.st_size,
  951             'mtime':  int(s.st_mtime),              # We strip these down to the integer value beacuse FP conversions on the back side can get confused.
  952             'ctime':  int(s.st_ctime),
  953             'atime':  int(s.st_atime),
  954             'mode':   s.st_mode,
  955             'uid':    s.st_uid,
  956             'gid':    s.st_gid,
  957             'dev':    s.st_dev
  958             }
  959 
  960         if support_xattr and args.xattr:
  961             try:
  962                 attrs = xattr.xattr(pathname, options=xattr.XATTR_NOFOLLOW)
  963                 #items = attrs.items()
  964                 if len(attrs):
  965                     # Convert to a set of readable string tuples
  966                     # We base64 encode the data chunk, as it's often binary
  967                     # Ugly, but unfortunately necessary
  968                     attr_string = json.dumps(dict([(str(x[0]), str(base64.b64encode(x[1]), 'utf8')) for x in sorted(attrs.items())]))
  969                     cks = addMeta(attr_string)
  970                     finfo['xattr'] = cks
  971             except:
  972                 logger.warning("Could not read extended attributes from %s.   Ignoring", pathname)
  973 
  974         if support_acl and args.acl and not stat.S_ISLNK(mode):
  975             # BUG:? FIXME:? ACL section doesn't seem to work on symbolic links.  Instead wants to follow the link.
  976             # Definitely an issue
  977             try:
  978                 if posix1e.has_extended(pathname):
  979                     acl = posix1e.ACL(file=pathname)
  980                     cks = addMeta(str(acl))
  981                     finfo['acl'] = cks
  982             except:
  983                 logger.warning("Could not read ACL's from %s.   Ignoring", pathname.encode('utf8', 'backslashreplace').decode('utf8'))
  984 
  985         # Insert into the inode DB
  986         inode = (s.st_ino, s.st_dev)
  987         if args.loginodes:
  988             args.loginodes.write(f"Add {str(inode)} {pathname}\n".encode('utf8'))
  989 
  990         inodeDB.insert(inode, finfo, pathname)
  991     else:
  992         if verbosity:
  993             logger.info("Skipping special file: %s", pathname)
  994         finfo = None
  995     return finfo
  996 
  997 def getDirContents(dirname, dirstat, excludes=set()):
  998     """ Read a directory, load any new exclusions, delete the excluded files, and return a list
  999         of the files, a list of sub directories, and the new list of excluded patterns """
 1000 
 1001     #logger.debug("Processing directory : %s", dir)
 1002     Util.accumulateStat(stats, 'dirs')
 1003     device = dirstat.st_dev
 1004 
 1005     # Process an exclude file which will be passed on down to the receivers
 1006     newExcludes = loadExcludeFile(os.path.join(dirname, excludeFile))
 1007     newExcludes = newExcludes.union(excludes)
 1008     excludes = newExcludes
 1009 
 1010     # Add a list of local files to exclude.  These won't get passed to lower directories
 1011     localExcludes = excludes.union(loadExcludeFile(os.path.join(dirname, args.localexcludefile)))
 1012 
 1013     files = []
 1014     subdirs = []
 1015 
 1016     try:
 1017         for f in filelist(dirname, localExcludes):
 1018             try:
 1019                 fInfo = mkFileInfo(f)
 1020                 if fInfo and (args.crossdev or device == fInfo['dev']):
 1021                     mode = fInfo["mode"]
 1022                     if stat.S_ISLNK(mode):
 1023                         Util.accumulateStat(stats, 'links')
 1024                     elif stat.S_ISREG(mode):
 1025                         Util.accumulateStat(stats, 'files')
 1026                         Util.accumulateStat(stats, 'backed', fInfo['size'])
 1027 
 1028                     if stat.S_ISDIR(mode):
 1029                         sub = os.path.join(dirname, f)
 1030                         if sub in excludeDirs:
 1031                             logger.debug("%s excluded.  Skipping", sub)
 1032                             continue
 1033                         else:
 1034                             subdirs.append(sub)
 1035 
 1036                     files.append(fInfo)
 1037             except (IOError, OSError) as e:
 1038                 logger.error("Error processing %s: %s", os.path.join(dirname, f), str(e))
 1039             except Exception as e:
 1040                 ## Is this necessary?  Fold into above?
 1041                 logger.error("Error processing %s: %s", os.path.join(dirname, f), str(e))
 1042                 exceptionLogger.log(e)
 1043     except (IOError, OSError) as e:
 1044         logger.error("Error reading directory %s: %s" ,dir, str(e))
 1045 
 1046     return (files, subdirs, excludes)
 1047 
 1048 def handleAckClone(message):
 1049     checkMessage(message, 'ACKCLN')
 1050     if verbosity > 2:
 1051         logger.debug("Processing ACKCLN: Up-to-date: %d New Content: %d", len(message['done']), len(message['content']))
 1052 
 1053     logdirs = logger.isEnabledFor(logging.DIRS)
 1054 
 1055     content = message.setdefault('content', {})
 1056     done    = message.setdefault('done', {})
 1057 
 1058     # Purge out what hasn't changed
 1059     for i in done:
 1060         inode = tuple(i)
 1061         if inode in cloneContents:
 1062             (path, files) = cloneContents[inode]
 1063             for f in files:
 1064                 key = (f['inode'], f['dev'])
 1065                 inodeDB.delete(key)
 1066             del cloneContents[inode]
 1067         else:
 1068             logger.error("Unable to locate info for %s", inode)
 1069         # And the directory.
 1070         inodeDB.delete(inode)
 1071 
 1072     # Process the directories that have changed
 1073     for i in content:
 1074         finfo = tuple(i)
 1075         if finfo in cloneContents:
 1076             (path, files) = cloneContents[finfo]
 1077             if logdirs:
 1078                 logger.log(logging.DIRS, "[R]: %s", Util.shortPath(path))
 1079             sendDirChunks(path, finfo, files)
 1080             del cloneContents[finfo]
 1081         else:
 1082             logger.error("Unable to locate info for %s", str(finfo))
 1083 
 1084 
 1085 def makeCloneMessage():
 1086     global cloneDirs
 1087     message = {
 1088         'message': 'CLN',
 1089         'clones': cloneDirs
 1090     }
 1091     cloneDirs = []
 1092     return message
 1093 
 1094 def sendClones():
 1095     message = makeCloneMessage()
 1096     setMessageID(message)
 1097     response = sendAndReceive(message)
 1098     checkMessage(response, 'ACKCLN')
 1099     handleAckClone(response)
 1100 
 1101 def flushClones():
 1102     if cloneDirs:
 1103         logger.debug("Flushing %d clones", len(cloneDirs))
 1104         if args.batchdirs:
 1105             batchMessage(makeCloneMessage())
 1106         else:
 1107             sendClones()
 1108 
 1109 def sendBatchMsgs():
 1110     global batchMsgs, _batchStartTime
 1111     batchSize = len(batchMsgs)
 1112     if batchSize <= 1:
 1113         # If there's only one, don't batch it up, just send it.
 1114         msg = batchMsgs[0]
 1115         batchMsgs = []
 1116         response = sendAndReceive(msg)
 1117     else:
 1118         logger.debug("Sending %d batch messages", len(batchMsgs))
 1119         message = {
 1120             'message'  : 'BATCH',
 1121             'batchsize': batchSize,
 1122             'batch'    : batchMsgs
 1123         }
 1124         msgId = setMessageID(message)
 1125         logger.debug("BATCH Starting. %s commands", len(batchMsgs))
 1126 
 1127         # Clear out the batch messages before sending, or you can get into an awkward loop.
 1128         # if it's not cleared out, the sendAndReceive can make a set of calls that will
 1129         # cause another message to be added to the batch (in pushFiles) which will cause the batch to
 1130         # be reprocessed.
 1131         batchMsgs = []
 1132 
 1133         response = sendAndReceive(message)
 1134         checkMessage(response, 'ACKBTCH')
 1135         respSize = len(response['responses'])
 1136         logger.debug("Got response.  %d responses", respSize)
 1137         if respSize != batchSize:
 1138             logger.error("Response size does not equal batch size: ID: %d B: %d R: %d", msgId, batchSize, respSize)
 1139             if logger.isEnabledFor(logging.DEBUG):
 1140                 msgs = set([x['msgid'] for x in batchMsgs])
 1141                 resps = set([x['respid'] for x in response['responses']])
 1142                 diffs1 = msgs.difference(resps)
 1143                 logger.debug("Missing Messages: %s", str(list(diffs1)))
 1144         logger.debug("BATCH Ending.")
 1145 
 1146     _batchStartTime = None
 1147     # Process the response messages
 1148     handleResponse(response)
 1149 
 1150 def flushBatchMsgs():
 1151     if len(batchMsgs):
 1152         sendBatchMsgs()
 1153         return True
 1154     else:
 1155         return False
 1156 
 1157 def sendPurge(relative):
 1158     """ Send a purge message.  Indicate if this time is relative (ie, days before now), or absolute. """
 1159     message =  { 'message': 'PRG' }
 1160     if purgePriority:
 1161         message['priority'] = purgePriority
 1162     if purgeTime:
 1163         message.update( { 'time': purgeTime, 'relative': relative })
 1164 
 1165     batchMessage(message, flush=True, batch=False)
 1166 
 1167 def sendDirChunks(path, inode, files):
 1168     """ Chunk the directory into dirslice sized chunks, and send each sequentially """
 1169     if crypt.encrypting():
 1170         path = crypt.encryptPath(path)
 1171     message = {
 1172         'message': 'DIR',
 1173         'path'   : path,
 1174         'inode'  : list(inode),
 1175     }
 1176 
 1177     chunkNum = 0
 1178     for x in range(0, len(files), args.dirslice):
 1179         if verbosity > 3:
 1180             logger.debug("---- Generating chunk %d ----", chunkNum)
 1181         chunkNum += 1
 1182         chunk = files[x : x + args.dirslice]
 1183 
 1184         # Encrypt the names before sending them out
 1185         if crypt.encrypting():
 1186             for i in chunk:
 1187                 i['name'] = crypt.encryptFilename(i['name'])
 1188 
 1189         message["files"] = chunk
 1190         message["last"]  = (x + args.dirslice > len(files))
 1191         if verbosity > 3:
 1192             logger.debug("---- Sending chunk at %d ----", x)
 1193         batch = (len(chunk) < args.dirslice)
 1194         batchMessage(message, batch=batch)
 1195 
 1196     sendDirHash(inode)
 1197 
 1198 def makeMetaMessage():
 1199     global newmeta
 1200     message = {
 1201         'message': 'META',
 1202         'metadata': newmeta
 1203         }
 1204     newmeta = []
 1205     return message
 1206 
 1207 statusBar = None
 1208 
 1209 def initProgressBar(scheduler):
 1210     statusBar = ShortPathStatusBar("{__elapsed__} | Dirs: {dirs} | Files: {files} | Full: {new} | Delta: {delta} | Data: {dataSent!B} | {mode} ", stats, scheduler=scheduler)
 1211     statusBar.setValue('mode', '')
 1212     statusBar.setTrailer('')
 1213     statusBar.start()
 1214     return statusBar
 1215 
 1216 def setProgress(mode, name):
 1217     if statusBar:
 1218         statusBar.setValue('mode', mode)
 1219         statusBar.setTrailer(name)
 1220 
 1221 processedDirs = set()
 1222 
 1223 def recurseTree(dir, top, depth=0, excludes=[]):
 1224     """ Process a directory, send any contents along, and then dive down into subdirectories and repeat. """
 1225     global dirHashes
 1226 
 1227     newdepth = 0
 1228     if depth > 0:
 1229         newdepth = depth - 1
 1230 
 1231     setProgress("Dir:", dir)
 1232 
 1233     try:
 1234         s = os.lstat(dir)
 1235         if not stat.S_ISDIR(s.st_mode):
 1236             return
 1237 
 1238         # Mark that we've processed it before attempting to determine if we actually should
 1239         processedDirs.add(dir)
 1240 
 1241         if dir in excludeDirs:
 1242             logger.debug("%s excluded.  Skipping", dir)
 1243             return
 1244 
 1245         if os.path.lexists(os.path.join(dir, args.skipfile)):
 1246             logger.debug("Skip file found.  Skipping %s", dir)
 1247             return
 1248 
 1249         if args.skipcaches and os.path.lexists(os.path.join(dir, 'CACHEDIR.TAG')):
 1250             logger.debug("CACHEDIR.TAG file found.  Analyzing")
 1251             try:
 1252                 with open(os.path.join(dir, 'CACHEDIR.TAG'), 'r') as f:
 1253                     line = f.readline()
 1254                     if line.startswith('Signature: 8a477f597d28d172789f06886806bc55'):
 1255                         logger.debug("Valid CACHEDIR.TAG file found.  Skipping %s", dir)
 1256                         return
 1257             except Exception as e:
 1258                 logger.warning("Could not read %s.  Backing up directory %s", os.path.join(dir, 'CACHEDIR.TAG'), dir)
 1259                 exceptionLogger.log(e)
 1260 
 1261         (files, subdirs, subexcludes) = getDirContents(dir, s, excludes)
 1262 
 1263         h = Util.hashDir(crypt, files)
 1264         #logger.debug("Dir: %s (%d, %d): Hash: %s Size: %d.", Util.shortPath(dir), s.st_ino, s.st_dev, h[0], h[1])
 1265         dirHashes[(s.st_ino, s.st_dev)] = h
 1266 
 1267         # Figure out which files to clone, and which to update
 1268         if files and args.clones:
 1269             if len(files) > args.clonethreshold:
 1270                 newFiles = [f for f in files if max(f['ctime'], f['mtime']) >= lastTimestamp]
 1271                 oldFiles = [f for f in files if max(f['ctime'], f['mtime']) < lastTimestamp]
 1272             else:
 1273                 maxTime = max([max(x["ctime"], x["mtime"]) for x in files])
 1274                 if maxTime < lastTimestamp:
 1275                     oldFiles = files
 1276                     newFiles = []
 1277                 else:
 1278                     newFiles = files
 1279                     oldFiles = []
 1280         else:
 1281             newFiles = files
 1282             oldFiles = []
 1283 
 1284         if newFiles:
 1285             # There are new and (maybe) old files.
 1286             # First, save the hash.
 1287 
 1288             # Purge out any meta data that's been accumulated
 1289             if newmeta:
 1290                 batchMessage(makeMetaMessage())
 1291 
 1292             if oldFiles:
 1293                 # There are oldfiles.  Hash them.
 1294                 if logger.isEnabledFor(logging.DIRS):
 1295                     logger.log(logging.DIRS, "[A]: %s", Util.shortPath(dir))
 1296                 cloneDir(s.st_ino, s.st_dev, oldFiles, dir)
 1297             else:
 1298                 if logger.isEnabledFor(logging.DIRS):
 1299                     logger.log(logging.DIRS, "[B]: %s", Util.shortPath(dir))
 1300             sendDirChunks(os.path.relpath(dir, top), (s.st_ino, s.st_dev), newFiles)
 1301 
 1302         else:
 1303             # everything is old
 1304             if logger.isEnabledFor(logging.DIRS):
 1305                 logger.log(logging.DIRS, "[C]: %s", Util.shortPath(dir))
 1306             cloneDir(s.st_ino, s.st_dev, oldFiles, dir, info=h)
 1307 
 1308         # Make sure we're not at maximum depth
 1309         if depth != 1:
 1310             # Purge out the lists.  Allow garbage collection to take place.  These can get largish.
 1311             files = oldFiles = newFiles = None
 1312             # Process the sub directories
 1313             for subdir in sorted(subdirs):
 1314                 recurseTree(subdir, top, newdepth, subexcludes)
 1315     except ExitRecursionException:
 1316         raise
 1317     except OSError as e:
 1318         logger.error("Error handling directory: %s: %s", dir, str(e))
 1319         raise ExitRecursionException(e)
 1320         #traceback.print_exc()
 1321     except IOError as e:
 1322         logger.error("Error handling directory: %s: %s", dir, str(e))
 1323         exceptionLogger.log(e)
 1324         raise ExitRecursionException(e)
 1325     except Exception as e:
 1326         # TODO: Clean this up
 1327         exceptionLogger.log(e)
 1328         raise ExitRecursionException(e)
 1329 
 1330 
 1331 def cloneDir(inode, device, files, path, info=None):
 1332     """ Send a clone message, containing the hash of the filenames, and the number of files """
 1333     if info:
 1334         (h, s) = info
 1335     else:
 1336         (h, s) = Util.hashDir(crypt, files)
 1337 
 1338     message = {'inode':  inode, 'dev': device, 'numfiles': s, 'cksum': h}
 1339     cloneDirs.append(message)
 1340     cloneContents[(inode, device)] = (path, files)
 1341     if len(cloneDirs) >= args.clones:
 1342         flushClones()
 1343 
 1344 def splitDir(files, when):
 1345     newFiles = []
 1346     oldFiles = []
 1347     for f in files:
 1348         if f['mtime'] < when:
 1349             oldFiles.append(f)
 1350         else:
 1351             newFiles.append(f)
 1352     return newFiles, oldFiles
 1353 
 1354 
 1355 def setBackupName(args):
 1356     """ Calculate the name of the backup set """
 1357     name = args.name
 1358     priority = args.priority
 1359     auto = True
 1360 
 1361     # If a name has been specified, we're not an automatic set.
 1362     if name:
 1363         auto = False
 1364     #else:
 1365     #   # Else, no name specified, we're auto.  Create a default name.
 1366     #   name = time.strftime("Backup_%Y-%m-%d_%H:%M:%S")
 1367     return (name, priority, auto)
 1368 
 1369 def setPurgeValues(args):
 1370     global purgeTime, purgePriority
 1371     if args.purge:
 1372         purgePriority = args.priority
 1373         if args.purgeprior:
 1374             purgePriority = args.purgeprior
 1375         if args.purgedays:
 1376             purgeTime = args.purgedays * 3600 * 24
 1377         if args.purgehours:
 1378             purgeTime = args.purgehours * 3600
 1379         if args.purgetime:
 1380             cal = parsedatetime.Calendar()
 1381             (then, success) = cal.parse(args.purgetime)
 1382             if success:
 1383                 purgeTime = time.mktime(then)
 1384             else:
 1385                 #logger.error("Could not parse --keep-time argument: %s", args.purgetime)
 1386                 raise Exception("Could not parse --keep-time argument: {} ".format(args.purgetime))
 1387 
 1388 
 1389 @functools.lru_cache(maxsize=128)
 1390 def mkExcludePattern(pattern):
 1391     logger.debug("Excluding {}", pattern)
 1392     if not pattern.startswith('/'):
 1393         pattern = '/**/' + pattern
 1394     return wildmatch.translate(pattern)
 1395 
 1396 def loadExcludeFile(name):
 1397     """ Load a list of patterns to exclude from a file. """
 1398     try:
 1399         with open(name) as f:
 1400             excludes = [mkExcludePattern(x.rstrip('\n')) for x in f.readlines()]
 1401         return set(excludes)
 1402     except IOError as e:
 1403         #traceback.print_exc()
 1404         return set()
 1405 
 1406 
 1407 # Load all the excludes we might want
 1408 def loadExcludes(args):
 1409     global excludeFile, globalExcludes
 1410     if not args.ignoreglobalexcludes:
 1411         globalExcludes = globalExcludes.union(loadExcludeFile(globalExcludeFile))
 1412     if args.cvs:
 1413         globalExcludes = globalExcludes.union(map(mkExcludePattern, cvsExcludes))
 1414     if args.excludes:
 1415         globalExcludes = globalExcludes.union(map(mkExcludePattern, args.excludes))
 1416     if args.excludefiles:
 1417         for f in args.excludefiles:
 1418             globalExcludes = globalExcludes.union(loadExcludeFile(f))
 1419     excludeFile         = args.excludefilename
 1420 
 1421 def loadExcludedDirs(args):
 1422     global excludeDirs
 1423     if args.excludedirs is not None:
 1424         excludeDirs.extend(list(map(Util.fullPath, args.excludedirs)))
 1425 
 1426 def sendMessage(message):
 1427     if verbosity > 4:
 1428         logger.debug("Send: %s", str(message))
 1429     if args.logmessages:
 1430         args.logmessages.write("Sending message %s %s\n" % (message.get('msgid', 'Unknown'), "-" * 40))
 1431         args.logmessages.write(pprint.pformat(message, width=250, compact=True) + '\n\n')
 1432     #setProgress("Sending...", "")
 1433     conn.send(message)
 1434 
 1435 def receiveMessage():
 1436     setProgress("Receiving...", "")
 1437     response = conn.receive()
 1438     if verbosity > 4:
 1439         logger.debug("Receive: %s", str(response))
 1440     if args.logmessages:
 1441         args.logmessages.write("Received message %s %s\n" % (response.get('respid', 'Unknown'), "-" * 40))
 1442         args.logmessages.write(pprint.pformat(response, width=250, compact=True) + '\n\n')
 1443     return response
 1444 
 1445 waittime = 0
 1446 
 1447 def sendAndReceive(message):
 1448     global waittime
 1449     s = time.time()
 1450     sendMessage(message)
 1451     response = receiveMessage()
 1452     e = time.time()
 1453     waittime += e - s
 1454     return response
 1455 
 1456 def sendKeys(password, client, includeKeys=True):
 1457     logger.debug("Sending keys")
 1458     (f, c) = crypt.getKeys()
 1459 
 1460     #salt, vkey = TardisCrypto.createSRPValues(password, client)
 1461 
 1462     (salt, vkey) = srp.create_salted_verification_key(client, password)
 1463     message = { "message": "SETKEYS",
 1464                 "filenameKey": f,
 1465                 "contentKey": c,
 1466                 "srpSalt": salt,
 1467                 "srpVkey":  vkey,
 1468                 "cryptoScheme": crypt.getCryptoScheme()
 1469               }
 1470     response = sendAndReceive(message)
 1471     checkMessage(response, 'ACKSETKEYS')
 1472     if response['response'] != 'OK':
 1473         logger.error("Could not set keys")
 1474 
 1475 currentBatch = None
 1476 currentResponse = None
 1477 
 1478 def handleResponse(response, doPush=True, pause=0):
 1479     global currentResponse, currentBatch
 1480     # TODO: REMOVE THIS DEBUG CODE and the pause parameter
 1481     if pause:
 1482         subs = ""
 1483         if response.get('message') == 'ACKBTCH':
 1484             subs = "-- " + " ".join(map(lambda x: x.get('message', 'NONE') + " (" + str(x.get('respid', -1)) + ")" , response['responses']))
 1485         logger.warning("Sleeping for %d seconds.  Do your thing: %d %s %s", pause, response.get('respid', -1), response.get('message', 'NONE'), subs)
 1486         time.sleep(pause)
 1487     # END DEBUG
 1488     try:
 1489         currentResponse = response
 1490         msgtype = response['message']
 1491         if msgtype == 'ACKDIR':
 1492             handleAckDir(response)
 1493         elif msgtype == 'ACKCLN':
 1494             handleAckClone(response)
 1495         elif msgtype == 'ACKPRG':
 1496             pass
 1497         elif msgtype == 'ACKSUM':
 1498             handleAckSum(response)
 1499         elif msgtype == 'ACKMETA':
 1500             handleAckMeta(response)
 1501         elif msgtype == 'ACKDHSH':
 1502             # TODO: Respond
 1503             pass
 1504         elif msgtype == 'ACKCLICONFIG':
 1505             # Ignore
 1506             pass
 1507         elif msgtype == 'ACKCMDLN':
 1508             # Ignore
 1509             pass
 1510         elif msgtype == 'ACKBTCH':
 1511             currentBatch = response
 1512             for ack in response['responses']:
 1513                 handleResponse(ack, doPush=False, pause=0)
 1514             currentBatch = None
 1515         else:
 1516             logger.error("Unexpected response: %s", msgtype)
 1517 
 1518         if doPush:
 1519             pushFiles()
 1520     except Exception as e:
 1521         logger.error("Error handling response %s %s: %s", response.get('msgid'), response.get('message'), e)
 1522         logger.exception("Exception: ", exc_info=e)
 1523         logger.error(pprint.pformat(response, width=150, depth=5, compact=True))
 1524         exceptionLogger.log(e)
 1525 
 1526 _nextMsgId = 0
 1527 def setMessageID(message):
 1528     global _nextMsgId
 1529     #message['sessionid'] = str(sessionid)
 1530     message['msgid'] = _nextMsgId
 1531     _nextMsgId += 1
 1532     return message['msgid']
 1533 
 1534 _batchStartTime = None
 1535 
 1536 def batchMessage(message, batch=True, flush=False, response=True):
 1537     global _batchStartTime
 1538     setMessageID(message)
 1539 
 1540     batch = batch and (args.batchsize > 0)
 1541 
 1542     if batch:
 1543         batchMsgs.append(message)
 1544     now = time.time()
 1545     if _batchStartTime is None:
 1546         _batchStartTime = now
 1547 
 1548     if flush or not batch or len(batchMsgs) >= args.batchsize or (now - _batchStartTime) > args.batchduration:
 1549         flushClones()
 1550         flushBatchMsgs()
 1551     if not batch:
 1552         if response:
 1553             respmessage = sendAndReceive(message)
 1554             handleResponse(respmessage)
 1555         else:
 1556             sendMessage(message)
 1557 
 1558 def sendDirEntry(parent, device, files):
 1559     # send a fake root directory
 1560     message = {
 1561         'message': 'DIR',
 1562         'files': files,
 1563         'path' : None,
 1564         'inode': [parent, device],
 1565         'files': files,
 1566         'last' : True
 1567         }
 1568 
 1569     #for x in map(os.path.realpath, args.directories):
 1570         #(dir, name) = os.path.split(x)
 1571         #file = mkFileInfo(dir, name)
 1572         #if file and file["dir"] == 1:
 1573             #files.append(file)
 1574     #
 1575     # and send it.
 1576     batchMessage(message)
 1577 
 1578 def splitDirs(x):
 1579     root, rest = os.path.split(x)
 1580     if root and rest:
 1581         ret = splitDirs(root)
 1582         ret.append(rest)
 1583     elif root:
 1584         if root == '/':
 1585             ret = [root]
 1586         else:
 1587             ret = splitDirs(root)
 1588     else:
 1589         ret = [rest]
 1590     return ret
 1591 
 1592 def createPrefixPath(root, path):
 1593     """ Create common path directories.  Will be empty, except for path elements to the repested directories. """
 1594     rPath     = os.path.relpath(path, root)
 1595     logger.debug("Making prefix path for: %s as %s", path, rPath)
 1596     pathDirs  = splitDirs(rPath)
 1597     parent    = 0
 1598     parentDev = 0
 1599     current   = root
 1600     for d in pathDirs:
 1601         dirPath = os.path.join(current, d)
 1602         st = os.lstat(dirPath)
 1603         f = mkFileInfo(FakeDirEntry(current, d))
 1604         if crypt.encrypting():
 1605             f['name'] = crypt.encryptFilename(f['name'])
 1606         if dirPath not in processedDirs:
 1607             logger.debug("Sending dir entry for: %s", dirPath)
 1608             sendDirEntry(parent, parentDev, [f])
 1609             processedDirs.add(dirPath)
 1610         parent    = st.st_ino
 1611         parentDev = st.st_dev
 1612         current   = dirPath
 1613 
 1614 def setCrypto(confirm, chkStrength=False, version=None):
 1615     global srpUsr, crypt
 1616     password = Util.getPassword(args.password, args.passwordfile, args.passwordprog, "Password for %s:" % (args.client),
 1617                                 confirm=confirm, strength=chkStrength, allowNone = False)
 1618     srpUsr = srp.User(args.client, password)
 1619     crypt = TardisCrypto.getCrypto(version, password, args.client)
 1620     logger.debug("Using %s Crypto scheme", crypt.getCryptoScheme())
 1621     return password
 1622 
 1623 def doSendKeys(password):
 1624     if srpUsr is None:
 1625         password = setCrypto(True, True, cryptoVersion)
 1626     logger.debug("Sending keys")
 1627     crypt.genKeys()
 1628     (f, c) = crypt.getKeys()
 1629     #salt, vkey = crypt.createSRPValues(password, args.client)
 1630     (salt, vkey) = srp.create_salted_verification_key(args.client, password)
 1631     message = { "message": "SETKEYS",
 1632                 "filenameKey": f,
 1633                 "contentKey": c,
 1634                 "srpSalt": salt,
 1635                 "srpVkey": vkey,
 1636                 "cryptoScheme": crypt.getCryptoScheme()
 1637               }
 1638     resp = sendAndReceive(message)
 1639     return resp
 1640 
 1641 def doSrpAuthentication(response):
 1642     try:
 1643         setCrypto(False, args.create, response['cryptoScheme'])
 1644 
 1645         srpUname, srpValueA = srpUsr.start_authentication()
 1646         logger.debug("Starting Authentication: %s, %s", srpUname, hexlify(srpValueA))
 1647         message = {
 1648             'message': 'AUTH1',
 1649             'srpUname': base64.b64encode(bytes(srpUname, 'utf8')),           # Probably unnecessary, uname == client
 1650             'srpValueA': base64.b64encode(srpValueA),
 1651             }
 1652         resp = sendAndReceive(message)
 1653 
 1654         if resp['status'] == 'AUTHFAIL':
 1655             raise AuthenticationFailed("Authentication Failed")
 1656 
 1657 
 1658         srpValueS = base64.b64decode(resp['srpValueS'])
 1659         srpValueB = base64.b64decode(resp['srpValueB'])
 1660 
 1661         logger.debug("Received Challenge : %s, %s", hexlify(srpValueS), hexlify(srpValueB))
 1662 
 1663         srpValueM = srpUsr.process_challenge(srpValueS, srpValueB)
 1664 
 1665         if srpValueM is None:
 1666             raise AuthenticationFailed("Authentication Failed")
 1667 
 1668         logger.debug("Authentication Challenge response: %s", hexlify(srpValueM))
 1669 
 1670         message = {
 1671             'message': 'AUTH2',
 1672             'srpValueM': base64.b64encode(srpValueM)
 1673         }
 1674 
 1675         resp = sendAndReceive(message)
 1676         if resp['status'] == 'AUTHFAIL':
 1677             raise AuthenticationFailed("Authentication Failed")
 1678         elif resp['status'] != 'OK':
 1679             raise Exception(resp['error'])
 1680         srpHamk = base64.b64decode(resp['srpValueHAMK'])
 1681         srpUsr.verify_session(srpHamk)
 1682         return resp
 1683     except KeyError as e:
 1684         logger.error("Key not found %s", str(e))
 1685         raise AuthenticationFailed("response incomplete")
 1686     
 1687 
 1688 def startBackup(name, priority, client, autoname, force, full=False, create=False, password=None, version=Tardis.__versionstring__):
 1689     global sessionid, clientId, lastTimestamp, backupName, newBackup, filenameKey, contentKey, crypt
 1690 
 1691     # Create a BACKUP message
 1692     message = {
 1693             'message'   : 'BACKUP',
 1694             'host'      : client,
 1695             'encoding'  : encoding,
 1696             'priority'  : priority,
 1697             'autoname'  : autoname,
 1698             'force'     : force,
 1699             'time'      : time.time(),
 1700             'version'   : version,
 1701             'full'      : full,
 1702             'create'    : create
 1703     }
 1704 
 1705     # BACKUP { json message }
 1706     resp = sendAndReceive(message)
 1707 
 1708     if resp['status'] == 'NEEDKEYS':
 1709         resp = doSendKeys(password)
 1710     if resp['status'] == 'AUTH':
 1711         resp = doSrpAuthentication(resp)
 1712 
 1713     if resp['status'] != 'OK':
 1714         errmesg = "BACKUP request failed"
 1715         if 'error' in resp:
 1716             errmesg = errmesg + ": " + resp['error']
 1717         raise Exception(errmesg)
 1718 
 1719     sessionid      = uuid.UUID(resp['sessionid'])
 1720     clientId       = uuid.UUID(resp['clientid'])
 1721     lastTimestamp  = float(resp['prevDate'])
 1722     backupName     = resp['name']
 1723     newBackup      = resp['new']
 1724     if 'filenameKey' in resp:
 1725         filenameKey = resp['filenameKey']
 1726     if 'contentKey' in resp:
 1727         contentKey = resp['contentKey']
 1728     if crypt is None:
 1729         crypt = TardisCrypto.getCrypto(TardisCrypto.noCryptoScheme, None, client)
 1730 
 1731     # Set up the encryption, if needed.
 1732     ### TODO
 1733     (f, c) = (None, None)
 1734 
 1735     if newBackup == 'NEW':
 1736         # if new DB, generate new keys, and save them appropriately.
 1737         if password:
 1738             logger.debug("Generating new keys")
 1739             crypt.genKeys()
 1740             if args.keys:
 1741                 (f, c) = crypt.getKeys()
 1742                 Util.saveKeys(Util.fullPath(args.keys), clientId, f, c)
 1743             else:
 1744                 sendKeys(password, client)
 1745         else:
 1746             if args.keys:
 1747                 (f, c) = crypt.getKeys()
 1748                 Util.saveKeys(Util.fullPath(args.keys), clientId, f, c)
 1749     elif crypt.encrypting():
 1750         # Otherwise, load the keys from the appropriate place
 1751         if args.keys:
 1752             (f, c) = Util.loadKeys(args.keys, clientId)
 1753         else:
 1754             f = filenameKey
 1755             c = contentKey
 1756         if not (f and c):
 1757             logger.critical("Unable to load keyfile: %s", args.keys)
 1758             sys.exit(1)
 1759         crypt.setKeys(f, c)
 1760 
 1761 def getConnection(server, port, maxBandwidth=None):
 1762     #if args.protocol == 'json':
 1763     #    conn = Connection.JsonConnection(server, port, name, priority, client, autoname=auto, token=token, force=args.force, timeout=args.timeout, full=args.full)
 1764     #    setEncoder("base64")
 1765     #elif args.protocol == 'bson':
 1766     #    conn = Connection.BsonConnection(server, port, name, priority, client, autoname=auto, token=token, compress=args.compressmsgs, force=args.force, timeout=args.timeout, full=args.full)
 1767     #    setEncoder("bin")
 1768     #elif args.protocol == 'msgp':
 1769     throttler = None
 1770     #if maxBandwidth:
 1771     #    throttler = Throttler(maxBandwidth, blocking=True)
 1772 
 1773     conn = Connection.MsgPackConnection(server, port, compress=args.compressmsgs, timeout=args.timeout)
 1774     setEncoder("bin")
 1775     return conn
 1776 
 1777 def splitList(line):
 1778     if not line:
 1779         return []
 1780     else:
 1781         return shlex.split(line.strip())
 1782 
 1783 def checkConfig(c, t):
 1784     # Check things in the config file that might be confusing
 1785     # CompressedBuffer will convert True or 1 to zlib, anything else not in the list to none
 1786     comp = c.get(t, 'CompressData').lower()
 1787     if (comp == 'true') or (comp == '1'):
 1788         c.set(t, 'CompressData', 'zlib')
 1789     elif not (comp in CompressedBuffer.getCompressors()):
 1790         c.set(t, 'CompressData', 'none')
 1791 
 1792 def processCommandLine():
 1793     """ Do the command line thing.  Register arguments.  Parse it. """
 1794     def _d(help):
 1795         """ Only print the help message if --debug is specified """
 1796         return help if args.debug else argparse.SUPPRESS
 1797 
 1798     _def = 'Default: %(default)s'
 1799 
 1800     # Use the custom arg parser, which handles argument files more cleanly
 1801     parser = CustomArgumentParser(description='Tardis Backup Client', fromfile_prefix_chars='@', formatter_class=Util.HelpFormatter, add_help=False,
 1802                                   epilog='Options can be specified in files, with the filename specified by an @sign: e.g. "%(prog)s @args.txt" will read arguments from args.txt')
 1803 
 1804     parser.add_argument('--config',                 dest='config', default=Defaults.getDefault('TARDIS_CONFIG'),        help='Location of the configuration file. ' + _def)
 1805     parser.add_argument('--job',                    dest='job', default=Defaults.getDefault('TARDIS_JOB'),              help='Job Name within the configuration file. ' + _def)
 1806     parser.add_argument('--debug',                  dest='debug', default=False, action='store_true',                   help=argparse.SUPPRESS)
 1807     (args, remaining) = parser.parse_known_args()
 1808 
 1809     t = args.job
 1810     c = configparser.RawConfigParser(configDefaults, allow_no_value=True)
 1811     if args.config:
 1812         c.read(args.config)
 1813         if not c.has_section(t):
 1814             sys.stderr.write("WARNING: No Job named %s listed.  Using defaults.  Jobs available: %s\n" %(t, str(c.sections()).strip('[]')))
 1815             c.add_section(t)                    # Make it safe for reading other values from.
 1816         checkConfig(c, t)
 1817     else:
 1818         c.add_section(t)                        # Make it safe for reading other values from.
 1819 
 1820     locgroup = parser.add_argument_group("Local Backup options")
 1821     locgroup.add_argument('--database', '-D',     dest='database',        default=c.get(t, 'BaseDir'), help='Dabatase directory (Default: %(default)s)')
 1822     locgroup.add_argument('--dbdir',              dest='dbdir',           default=c.get(t, 'DBDir'),   help='Location of database files (if different from database directory above) (Default: %(default)s)')
 1823     locgroup.add_argument('--dbname', '-N',       dest='dbname',          default=c.get(t, 'DBName'),  help='Use the database name (Default: %(default)s)')
 1824     locgroup.add_argument('--schema',             dest='schema',          default=c.get(t, 'Schema'),  help='Path to the schema to use (Default: %(default)s)')
 1825 
 1826     remotegroup = parser.add_argument_group("Remote Server options")
 1827     remotegroup.add_argument('--server', '-s',           dest='server', default=c.get(t, 'Server'),                          help='Set the destination server. ' + _def)
 1828     remotegroup.add_argument('--port', '-p',             dest='port', type=int, default=c.getint(t, 'Port'),                 help='Set the destination server port. ' + _def)
 1829 
 1830     modegroup = parser.add_mutually_exclusive_group()
 1831     modegroup.add_argument('--local',               dest='local', action='store_true',  default=c.get(t, 'Local'), help='Run as a local job')
 1832     modegroup.add_argument('--remote',              dest='local', action='store_false', default=c.get(t, 'Local'), help='Run against a remote server')
 1833 
 1834     parser.add_argument('--log', '-l',              dest='logfiles', action='append', default=splitList(c.get(t, 'LogFiles')), nargs="?", const=sys.stderr,
 1835                         help='Send logging output to specified file.  Can be repeated for multiple logs. Default: stderr')
 1836 
 1837     parser.add_argument('--client', '-C',           dest='client', default=c.get(t, 'Client'),                          help='Set the client name.  ' + _def)
 1838     parser.add_argument('--force',                  dest='force', action=Util.StoreBoolean, default=c.getboolean(t, 'Force'),
 1839                         help='Force the backup to take place, even if others are currently running.  ' + _def)
 1840     parser.add_argument('--full',                   dest='full', action=Util.StoreBoolean, default=c.getboolean(t, 'Full'),
 1841                         help='Perform a full backup, with no delta information. ' + _def)
 1842     parser.add_argument('--name',   '-n',           dest='name', default=None,                                          help='Set the backup name.  Leave blank to assign name automatically')
 1843     parser.add_argument('--create',                 dest='create', default=False, action=Util.StoreBoolean,             help='Create a new client.')
 1844 
 1845     parser.add_argument('--timeout',                dest='timeout', default=300.0, type=float, const=None,              help='Set the timeout to N seconds.  ' + _def)
 1846 
 1847     passgroup = parser.add_argument_group("Password/Encryption specification options")
 1848     pwgroup = passgroup.add_mutually_exclusive_group()
 1849     pwgroup.add_argument('--password', '-P',        dest='password', default=c.get(t, 'Password'), nargs='?', const=True,
 1850                          help='Password.  Enables encryption')
 1851     pwgroup.add_argument('--password-file', '-F',   dest='passwordfile', default=c.get(t, 'PasswordFile'),              help='Read password from file.  Can be a URL (HTTP/HTTPS or FTP)')
 1852     pwgroup.add_argument('--password-prog',         dest='passwordprog', default=c.get(t, 'PasswordProg'),              help='Use the specified command to generate the password on stdout')
 1853 
 1854     passgroup.add_argument('--crypt',               dest='cryptoScheme', type=int, choices=range(TardisCrypto.defaultCryptoScheme+1),
 1855                            default=None,
 1856                            help="Crypto scheme to use.  0-4\n" + TardisCrypto.getCryptoNames())
 1857 
 1858     passgroup.add_argument('--keys',                dest='keys', default=c.get(t, 'KeyFile'),
 1859                            help='Load keys from file.  Keys are not stored in database')
 1860 
 1861     parser.add_argument('--send-config', '-S',      dest='sendconfig', action=Util.StoreBoolean, default=c.getboolean(t, 'SendClientConfig'),
 1862                         help='Send the client config (effective arguments list) to the server for debugging.  Default=%(default)s');
 1863 
 1864     parser.add_argument('--compress-data',  '-Z',   dest='compress', const='zlib', default=c.get(t, 'CompressData'), nargs='?', choices=CompressedBuffer.getCompressors(),
 1865                         help='Compress files.  ' + _def)
 1866     parser.add_argument('--compress-min',           dest='mincompsize', type=int, default=c.getint(t, 'CompressMin'),   help='Minimum size to compress.  ' + _def)
 1867     parser.add_argument('--nocompress-types',       dest='nocompressfile', default=splitList(c.get(t, 'NoCompressFile')), action='append',
 1868                         help='File containing a list of MIME types to not compress.  ' + _def)
 1869     parser.add_argument('--nocompress', '-z',       dest='nocompress', default=splitList(c.get(t, 'NoCompress')), action='append',
 1870                         help='MIME type to not compress. Can be repeated')
 1871     if support_xattr:
 1872         parser.add_argument('--xattr',              dest='xattr', default=True, action=Util.StoreBoolean,               help='Backup file extended attributes')
 1873     if support_acl:
 1874         parser.add_argument('--acl',                dest='acl', default=True, action=Util.StoreBoolean,                 help='Backup file access control lists')
 1875 
 1876 
 1877     parser.add_argument('--priority',           dest='priority', type=int, default=None,                                help='Set the priority of this backup')
 1878     parser.add_argument('--maxdepth', '-d',     dest='maxdepth', type=int, default=0,                                   help='Maximum depth to search')
 1879     parser.add_argument('--crossdevice',        dest='crossdev', action=Util.StoreBoolean, default=False,               help='Cross devices. ' + _def)
 1880 
 1881     parser.add_argument('--basepath',           dest='basepath', default='full', choices=['none', 'common', 'full'],    help='Select style of root path handling ' + _def)
 1882 
 1883     excgrp = parser.add_argument_group('Exclusion options', 'Options for handling exclusions')
 1884     excgrp.add_argument('--cvs-ignore',                 dest='cvs', default=c.getboolean(t, 'IgnoreCVS'), action=Util.StoreBoolean,
 1885                         help='Ignore files like CVS.  ' + _def)
 1886     excgrp.add_argument('--skip-caches',                dest='skipcaches', default=c.getboolean(t, 'SkipCaches'),action=Util.StoreBoolean,
 1887                         help='Skip directories with valid CACHEDIR.TAG files.  ' + _def)
 1888     excgrp.add_argument('--exclude', '-x',              dest='excludes', action='append', default=splitList(c.get(t, 'ExcludePatterns')),
 1889                         help='Patterns to exclude globally (may be repeated)')
 1890     excgrp.add_argument('--exclude-file', '-X',         dest='excludefiles', action='append',                           help='Load patterns from exclude file (may be repeated)')
 1891     excgrp.add_argument('--exclude-dir',                dest='excludedirs', action='append', default=splitList(c.get(t, 'ExcludeDirs')),
 1892                         help='Exclude certain directories by path')
 1893 
 1894     excgrp.add_argument('--exclude-file-name',          dest='excludefilename', default=c.get(t, 'ExcludeFileName'),
 1895                         help='Load recursive exclude files from this.  ' + _def)
 1896     excgrp.add_argument('--local-exclude-file-name',    dest='localexcludefile', default=c.get(t, 'LocalExcludeFileName'),
 1897                         help='Load local exclude files from this.  ' + _def)
 1898     excgrp.add_argument('--skip-file-name',             dest='skipfile', default=c.get(t, 'SkipFileName'),
 1899                         help='File to indicate to skip a directory.  ' + _def)
 1900     excgrp.add_argument('--exclude-no-access',          dest='skipNoAccess', default=c.get(t, 'ExcludeNoAccess'), action=Util.StoreBoolean,
 1901                         help="Exclude files to which the runner has no permission- won't generate directory entry. " + _def)
 1902     excgrp.add_argument('--ignore-global-excludes',     dest='ignoreglobalexcludes', action=Util.StoreBoolean, default=False,
 1903                         help='Ignore the global exclude file.  ' + _def)
 1904 
 1905     comgrp = parser.add_argument_group('Communications options', 'Options for specifying details about the communications protocol.')
 1906     comgrp.add_argument('--compress-msgs', '-Y',    dest='compressmsgs', nargs='?', const='snappy',
 1907                         choices=['none', 'zlib', 'zlib-stream', 'snappy'], default=c.get(t, 'CompressMsgs'),
 1908                         help='Compress messages.  ' + _def)
 1909 
 1910     comgrp.add_argument('--clones', '-L',           dest='clones', type=int, default=1024,              help=_d('Maximum number of clones per chunk.  0 to disable cloning.  ' + _def))
 1911     comgrp.add_argument('--minclones',              dest='clonethreshold', type=int, default=64,        help=_d('Minimum number of files to do a partial clone.  If less, will send directory as normal: ' + _def))
 1912     comgrp.add_argument('--batchdir', '-B',         dest='batchdirs', type=int, default=16,             help=_d('Maximum size of small dirs to send.  0 to disable batching.  ' + _def))
 1913     comgrp.add_argument('--batchsize',              dest='batchsize', type=int, default=100,            help=_d('Maximum number of small dirs to batch together.  ' + _def))
 1914     comgrp.add_argument('--batchduration',          dest='batchduration', type=float, default=30.0,     help=_d('Maximum time to hold a batch open.  ' + _def))
 1915     comgrp.add_argument('--chunksize',              dest='chunksize', type=int, default=256*1024,       help=_d('Chunk size for sending data.  ' + _def))
 1916     comgrp.add_argument('--dirslice',               dest='dirslice', type=int, default=128*1024,        help=_d('Maximum number of directory entries per message.  ' + _def))
 1917     comgrp.add_argument('--logmessages',            dest='logmessages', type=argparse.FileType('w'),    help=_d('Log messages to file'))
 1918     #comgrp.add_argument('--protocol',               dest='protocol', default="msgp", choices=['json', 'bson', 'msgp'],
 1919     #                    help=_d('Protocol for data transfer.  ' + _def))
 1920     comgrp.add_argument('--signature',              dest='signature', default=c.getboolean(t, 'SendSig'), action=Util.StoreBoolean,
 1921                         help=_d('Always send a signature.  ' + _def))
 1922 
 1923     parser.add_argument('--deltathreshold',         dest='deltathreshold', default=66, type=int,
 1924                         help=_d('If delta file is greater than this percentage of the original, a full version is sent.  ' + _def))
 1925 
 1926     parser.add_argument('--sanity',                 dest='sanity', default=False, action=Util.StoreBoolean, help=_d('Run sanity checks to determine if everything is pushed to server'))
 1927     parser.add_argument('--loginodes',              dest='loginodes', default=None, type=argparse.FileType('wb'), help=_d('Log inode actions, and messages'))
 1928 
 1929     purgegroup = parser.add_argument_group("Options for purging old backup sets")
 1930     purgegroup.add_argument('--purge',              dest='purge', action=Util.StoreBoolean, default=c.getboolean(t, 'Purge'),  help='Purge old backup sets when backup complete.  ' + _def)
 1931     purgegroup.add_argument('--purge-priority',     dest='purgeprior', type=int, default=None,              help='Delete below this priority (Default: Backup priority)')
 1932 
 1933     prggroup = purgegroup.add_mutually_exclusive_group()
 1934     prggroup.add_argument('--keep-days',        dest='purgedays', type=int, default=None,           help='Number of days to keep')
 1935     prggroup.add_argument('--keep-hours',       dest='purgehours', type=int, default=None,          help='Number of hours to keep')
 1936     prggroup.add_argument('--keep-time',        dest='purgetime', default=None,                     help='Purge before this time.  Format: YYYY/MM/DD:hh:mm')
 1937 
 1938     parser.add_argument('--stats',              action=Util.StoreBoolean, dest='stats', default=c.getboolean(t, 'Stats'),
 1939                         help='Print stats about the transfer.  Default=%(default)s')
 1940     parser.add_argument('--report',             dest='report', choices=['all', 'dirs', 'none'], const='all', default=c.get(t, 'Report'), nargs='?',
 1941                         help='Print a report on all files or directories transferred.  ' + _def)
 1942     parser.add_argument('--verbose', '-v',      dest='verbose', action='count', default=c.getint(t, 'Verbosity'),
 1943                         help='Increase the verbosity')
 1944     parser.add_argument('--progress',           dest='progress', action='store_true',               help='Show a one-line progress bar.')
 1945 
 1946     parser.add_argument('--exclusive',          dest='exclusive', action=Util.StoreBoolean, default=True, help='Make sure the client only runs one job at a time. ' + _def)
 1947     parser.add_argument('--exceptions',         dest='exceptions', default=False, action=Util.StoreBoolean, help='Log full exception details')
 1948     parser.add_argument('--logtime',            dest='logtime', default=False, action=Util.StoreBoolean, help='Log time')
 1949     parser.add_argument('--logcolor',           dest='logcolor', default=True, action=Util.StoreBoolean, help='Generate colored logs')
 1950 
 1951     parser.add_argument('--version',            action='version', version='%(prog)s ' + Tardis.__versionstring__, help='Show the version')
 1952     parser.add_argument('--help', '-h',         action='help')
 1953 
 1954     Util.addGenCompletions(parser)
 1955 
 1956     parser.add_argument('directories',          nargs='*', default=splitList(c.get(t, 'Directories')), help="List of directories to sync")
 1957 
 1958     args = parser.parse_args(remaining)
 1959 
 1960     return (args, c, t)
 1961 
 1962 def parseServerInfo(args):
 1963     """ Break up the server info passed in into useable chunks """
 1964     serverStr = args.server
 1965     #logger.debug("Got server string: %s", serverStr)
 1966     if not serverStr.startswith('tardis://'):
 1967         serverStr = 'tardis://' + serverStr
 1968     try:
 1969         info = urllib.parse.urlparse(serverStr)
 1970         if info.scheme != 'tardis':
 1971             raise Exception("Invalid URL scheme: {}".format(info.scheme))
 1972 
 1973         sServer = info.hostname
 1974         sPort   = info.port
 1975         sClient = info.path.lstrip('/')
 1976 
 1977     except Exception as e:
 1978         raise Exception("Invalid URL: {} -- {}".format(args.server, e.message))
 1979 
 1980     server = sServer or args.server
 1981     port = sPort or args.port
 1982     client = sClient or args.client
 1983 
 1984     return (server, port, client)
 1985 
 1986 def setupLogging(logfiles, verbosity, logExceptions):
 1987     global logger, exceptionLogger
 1988 
 1989     # Define a couple custom logging levels
 1990     logging.STATS = logging.INFO + 1
 1991     logging.DIRS  = logging.INFO - 1
 1992     logging.FILES = logging.INFO - 2
 1993     logging.MSGS  = logging.INFO - 3
 1994     logging.addLevelName(logging.STATS, "STAT")
 1995     logging.addLevelName(logging.FILES, "FILE")
 1996     logging.addLevelName(logging.DIRS,  "DIR")
 1997     logging.addLevelName(logging.MSGS,  "MSG")
 1998 
 1999     levels = [logging.STATS, logging.INFO, logging.DIRS, logging.FILES, logging.MSGS, logging.DEBUG] #, logging.TRACE]
 2000 
 2001     # Don't want logging complaining within it's own runs.
 2002     logging.raiseExceptions = False
 2003 
 2004     # Create some default colors
 2005     colors = colorlog.default_log_colors.copy()
 2006     colors.update({
 2007                     'STAT': 'cyan',
 2008                     'DIR':  'cyan,bold',
 2009                     'FILE': 'cyan',
 2010                     'DEBUG': 'green'
 2011                   })
 2012 
 2013     msgOnlyFmt = '%(message)s'
 2014     if args.logtime:
 2015         #formatter = MessageOnlyFormatter(levels=[logging.STATS], fmt='%(asctime)s %(levelname)s: %(message)s')
 2016         formats = { logging.STATS: msgOnlyFmt }
 2017         defaultFmt = '%(asctime)s %(levelname)s: %(message)s'
 2018         cDefaultFmt = '%(asctime)s %(log_color)s%(levelname)s%(reset)s: %(message)s'
 2019     else:
 2020         formats = { logging.INFO: msgOnlyFmt, logging.STATS: msgOnlyFmt }
 2021         defaultFmt = '%(levelname)s: %(message)s'
 2022         cDefaultFmt = '%(log_color)s%(levelname)s%(reset)s: %(message)s'
 2023 
 2024     # If no log file specified, log to stderr
 2025     if len(logfiles) == 0:
 2026         logfiles.append(sys.stderr)
 2027 
 2028     # Generate a handler and formatter for each logfile
 2029     for logfile in logfiles:
 2030         if type(logfile) is str:
 2031             if logfile == ':STDERR:':
 2032                 isatty = os.isatty(sys.stderr.fileno())
 2033                 handler = Util.ClearingStreamHandler(sys.stderr)
 2034             elif logfile == ':STDOUT:':
 2035                 isatty = os.isatty(sys.stdout.fileno())
 2036                 handler = Util.ClearingStreamHandler(sys.stdout)
 2037             else:
 2038                 isatty = False
 2039                 handler = logging.handlers.WatchedFileHandler(Util.fullPath(logfile))
 2040         else:
 2041             isatty = os.isatty(logfile.fileno())
 2042             handler = Util.ClearingStreamHandler(logfile)
 2043 
 2044         if isatty and args.logcolor:
 2045             formatter = MultiFormatter.MultiFormatter(default_fmt=cDefaultFmt, formats=formats, baseclass=colorlog.ColoredFormatter, log_colors=colors, reset=True)
 2046         else:
 2047             formatter = MultiFormatter.MultiFormatter(default_fmt=defaultFmt, formats=formats)
 2048 
 2049         handler.setFormatter(formatter)
 2050         logging.root.addHandler(handler)
 2051 
 2052     # Default logger
 2053     logger = logging.getLogger('')
 2054 
 2055     # Pick a level.  Lowest specified level if verbosity is too large.
 2056     loglevel = levels[verbosity] if verbosity < len(levels) else levels[-1]
 2057     logger.setLevel(loglevel)
 2058 
 2059     # Mark if we're logging exceptions
 2060     exceptionLogger = Util.ExceptionLogger(logger, logExceptions)
 2061 
 2062     # Create a special logger just for messages
 2063     return logger
 2064 
 2065 def printStats(starttime, endtime):
 2066     connstats = conn.getStats()
 2067 
 2068     duration = endtime - starttime
 2069     duration = datetime.timedelta(duration.days, duration.seconds, duration.seconds - (duration.seconds % 100000))          # Truncate the microseconds
 2070 
 2071     logger.log(logging.STATS, "Runtime:          {}".format(duration))
 2072     logger.log(logging.STATS, "Backed Up:        Dirs: {:,}  Files: {:,}  Links: {:,}  Total Size: {:}".format(stats['dirs'], stats['files'], stats['links'], Util.fmtSize(stats['backed'])))
 2073     logger.log(logging.STATS, "Files Sent:       Full: {:,}  Deltas: {:,}".format(stats['new'], stats['delta']))
 2074     logger.log(logging.STATS, "Data Sent:        Sent: {:}   Backed: {:}".format(Util.fmtSize(stats['dataSent']), Util.fmtSize(stats['dataBacked'])))
 2075     logger.log(logging.STATS, "Messages:         Sent: {:,} ({:}) Received: {:,} ({:})".format(connstats['messagesSent'], Util.fmtSize(connstats['bytesSent']), connstats['messagesRecvd'], Util.fmtSize(connstats['bytesRecvd'])))
 2076     logger.log(logging.STATS, "Data Sent:        {:}".format(Util.fmtSize(stats['dataSent'])))
 2077 
 2078     if (stats['denied'] or stats['gone']):
 2079         logger.log(logging.STATS, "Files Not Sent:   Disappeared: {:,}  Permission Denied: {:,}".format(stats['gone'], stats['denied']))
 2080 
 2081 
 2082     logger.log(logging.STATS, "Wait Times:   {:}".format(str(datetime.timedelta(0, waittime))))
 2083     logger.log(logging.STATS, "Sending Time: {:}".format(str(datetime.timedelta(0, Util._transmissionTime))))
 2084 
 2085 def pickMode():
 2086     if args.local != '' and args.local is not None:
 2087         if args.local is True or args.local == 'True':
 2088             if args.server is None:
 2089                 raise Exception("Remote mode specied without a server")
 2090             return True
 2091         elif args.local is False or args.local == 'False':
 2092             if args.database is None:
 2093                 raise Exception("Local mode specied without a database")
 2094             return False
 2095     else:
 2096         if args.server is not None and args.database is not None:
 2097             raise Exception("Both database and server specified.  Unable to determine mode.   Use --local/--remote switches")
 2098         if args.server is not None:
 2099             return False
 2100         elif args.database is not None:
 2101             return True
 2102         else:
 2103             raise Exception("Neither database nor remote server is set.   Unable to backup")
 2104 
 2105 
 2106 def printReport(repFormat):
 2107     lastDir = None
 2108     length = 0
 2109     numFiles = 0
 2110     deltas   = 0
 2111     dataSize = 0
 2112     logger.log(logging.STATS, "")
 2113     if report:
 2114         length = reduce(max, list(map(len, [x[1] for x in report])))
 2115         length = max(length, 50)
 2116 
 2117         filefmts = ['','KB','MB','GB', 'TB', 'PB']
 2118         dirfmts  = ['B','KB','MB','GB', 'TB', 'PB']
 2119         fmt  = '%-{}s %-6s %-10s %-10s'.format(length + 4)
 2120         fmt2 = '  %-{}s   %-6s %-10s %-10s'.format(length)
 2121         fmt3 = '  %-{}s   %-6s %-10s'.format(length)
 2122         fmt4 = '  %d files (%d full, %d delta, %s)'
 2123 
 2124         logger.log(logging.STATS, fmt, "FileName", "Type", "Size", "Sig Size")
 2125         logger.log(logging.STATS, fmt, '-' * (length + 4), '-' * 6, '-' * 10, '-' * 10)
 2126         for i in sorted(report):
 2127             r = report[i]
 2128             (d, f) = i
 2129 
 2130             if d != lastDir:
 2131                 if repFormat == 'dirs' and lastDir:
 2132                     logger.log(logging.STATS, fmt4, numFiles, numFiles - deltas, deltas, Util.fmtSize(dataSize, formats=dirfmts))
 2133                 numFiles = 0
 2134                 deltas = 0
 2135                 dataSize = 0
 2136                 logger.log(logging.STATS, "%s:", Util.shortPath(d, 80))
 2137                 lastDir = d
 2138 
 2139             numFiles += 1
 2140             if r['type'] == 'Delta':
 2141                 deltas += 1
 2142             dataSize += r['size']
 2143 
 2144             if repFormat == 'all' or repFormat is True:
 2145                 if r['sigsize']:
 2146                     logger.log(logging.STATS, fmt2, f, r['type'], Util.fmtSize(r['size'], formats=filefmts), Util.fmtSize(r['sigsize'], formats=filefmts))
 2147                 else:
 2148                     logger.log(logging.STATS, fmt3, f, r['type'], Util.fmtSize(r['size'], formats=filefmts))
 2149         if repFormat == 'dirs' and lastDir:
 2150             logger.log(logging.STATS, fmt4, numFiles, numFiles - deltas, deltas, Util.fmtSize(dataSize, formats=dirfmts))
 2151     else:
 2152         logger.log(logging.STATS, "No files backed up")
 2153 
 2154 def lockRun(server, port, client):
 2155     lockName = 'tardis_' + str(server) + '_' + str(port) + '_' + str(client)
 2156 
 2157     # Create our own pidfile path.  We do this in /tmp rather than /var/run as tardis may not be run by
 2158     # the superuser (ie, can't write to /var/run)
 2159     pidfile = pid.PidFile(piddir=tempfile.gettempdir(), pidname=lockName)
 2160 
 2161     try:
 2162         pidfile.create()
 2163     except pid.PidFileError as e:
 2164         raise Exception("Tardis already running: %s" % e)
 2165     return pidfile
 2166 
 2167 def mkBackendConfig(jobname):
 2168     bc = Backend.BackendConfig()
 2169     j = jobname
 2170     bc.umask           = Util.parseInt(config.get(j, 'Umask'))
 2171     bc.cksContent      = config.getint(j, 'CksContent')
 2172     bc.serverSessionID = socket.gethostname() + time.strftime("-%Y-%m-%d::%H:%M:%S%Z", time.gmtime())
 2173     bc.formats         = list(map(str.strip, config.get(j, 'Formats').split(',')))
 2174     bc.priorities      = list(map(int, config.get(j, 'Priorities').split(',')))
 2175     bc.keep            = list(map(int, config.get(j, 'KeepDays').split(',')))
 2176     bc.forceFull       = list(map(int, config.get(j, 'ForceFull').split(',')))
 2177 
 2178     bc.journal         = config.get(j, 'JournalFile')
 2179 
 2180     bc.savefull        = config.getboolean(j, 'SaveFull')
 2181     bc.maxChain        = config.getint(j, 'MaxDeltaChain')
 2182     bc.deltaPercent    = float(config.getint(j, 'MaxChangePercent')) / 100.0        # Convert to a ratio
 2183     bc.autoPurge       = config.getboolean(j, 'AutoPurge')
 2184     bc.saveConfig      = config.getboolean(j, 'SaveConfig')
 2185     bc.dbbackups       = config.getint(j, 'DBBackups')
 2186 
 2187     bc.user            = None
 2188     bc.group           = None
 2189 
 2190     bc.dbname          = args.dbname
 2191     bc.basedir         = args.database
 2192     bc.allowNew        = True
 2193     bc.allowUpgrades   = True
 2194 
 2195     if args.dbdir:
 2196         bc.dbdir       = args.dbdir
 2197     else:
 2198         bc.dbdir       = bc.basedir
 2199 
 2200     bc.allowOverrides  = True
 2201     bc.linkBasis       = config.getboolean(j, 'LinkBasis')
 2202 
 2203     bc.requirePW       = config.getboolean(j, 'RequirePassword')
 2204 
 2205     bc.sxip            = args.skipfile
 2206 
 2207     bc.exceptions      = args.exceptions
 2208 
 2209     return bc
 2210 
 2211 def runBackend(jobname):
 2212     conn = Connection.DirectConnection(args.timeout)
 2213     beConfig = mkBackendConfig(jobname)
 2214 
 2215     backend = Backend.Backend(conn.serverMessages, beConfig, logSession=False)
 2216     backendThread = threading.Thread(target=backend.runBackup, name="Backend")
 2217     backendThread.start()
 2218     return conn, backend, backendThread
 2219 
 2220 def main():
 2221     global starttime, args, config, conn, verbosity, crypt, noCompTypes, srpUsr, statusBar
 2222     # Read the command line arguments.
 2223     commandLine = ' '.join(sys.argv) + '\n'
 2224     (args, config, jobname) = processCommandLine()
 2225 
 2226     # Memory debugging.
 2227     # Enable only if you really need it.
 2228     #from dowser import launch_memory_usage_server
 2229     #launch_memory_usage_server()
 2230 
 2231     # Set up logging
 2232     verbosity=args.verbose if args.verbose else 0
 2233     setupLogging(args.logfiles, verbosity, args.exceptions)
 2234 
 2235     try:
 2236         starttime = datetime.datetime.now()
 2237         subserver = None
 2238 
 2239         # Get the actual names we're going to use
 2240         (server, port, client) = parseServerInfo(args)
 2241 
 2242         if args.exclusive:
 2243             lockRun(server, port, client)
 2244 
 2245         # Figure out the name and the priority of this backupset
 2246         (name, priority, auto) = setBackupName(args)
 2247 
 2248         # setup purge times
 2249         setPurgeValues(args)
 2250 
 2251         # Load the excludes
 2252         loadExcludes(args)
 2253 
 2254         # Load any excluded directories
 2255         loadExcludedDirs(args)
 2256 
 2257         # Error check the purge parameter.  Disable it if need be
 2258         #if args.purge and not (purgeTime is not None or auto):
 2259         #   logger.error("Must specify purge days with this option set")
 2260         #   args.purge=False
 2261 
 2262         # Load any password info
 2263         try:
 2264             password = Util.getPassword(args.password, args.passwordfile, args.passwordprog, prompt="Password for %s: " % (client),
 2265                                         confirm=args.create, strength=args.create)
 2266         except Exception as e:
 2267             logger.critical("Could not retrieve password.: %s", str(e))
 2268             if args.exceptions:
 2269                 logger.exception(e)
 2270             sys.exit(1)
 2271 
 2272         # Purge out the original password.  Maybe it might go away.
 2273         #if args.password:
 2274             #args.password = '-- removed --'
 2275 
 2276         if password or (args.create and args.cryptoScheme):
 2277             srpUsr = srp.User(client, password)
 2278 
 2279             if args.create:
 2280                 scheme = args.cryptoScheme if args.cryptoScheme is not None else TardisCrypto.defaultCryptoScheme
 2281                 crypt = TardisCrypto.getCrypto(scheme, password, client)
 2282         elif args.create:
 2283             crypt = TardisCrypto.getCrypto(TardisCrypto.noCryptoScheme, None, client)
 2284 
 2285         # If no compression types are specified, load the list
 2286         types = []
 2287         for i in args.nocompressfile:
 2288             try:
 2289                 logger.debug("Reading types to ignore from: %s", i)
 2290                 data = list(map(Util.stripComments, open(i, 'r').readlines()))
 2291                 types = types + [x for x in data if len(x)]
 2292             except Exception as e:
 2293                 logger.error("Could not load nocompress types list from: %s", i)
 2294                 raise e
 2295         types = types + args.nocompress
 2296         noCompTypes = set(types)
 2297         logger.debug("Types to ignore: %s", sorted(noCompTypes))
 2298 
 2299         # Calculate the base directories
 2300         directories = list(itertools.chain.from_iterable(list(map(glob.glob, list(map(Util.fullPath, args.directories))))))
 2301         if args.basepath == 'common':
 2302             rootdir = os.path.commonprefix(directories)
 2303             # If the rootdir is actually one of the directories, back off one directory
 2304             if rootdir in directories:
 2305                 rootdir  = os.path.split(rootdir)[0]
 2306         elif args.basepath == 'full':
 2307             rootdir = '/'
 2308         else:
 2309             # None, just using the final component of the pathname.
 2310             # Check that each final component is unique, or will cause server error.
 2311             names = {}
 2312             errors = False
 2313             for i in directories:
 2314                 x = os.path.split(i)[1]
 2315                 if x in names:
 2316                     logger.error("%s directory name (%s) is not unique.  Collides with %s", i, x, names[name])
 2317                     errors = True
 2318                 else:
 2319                     names[x] = i
 2320             if errors:
 2321                 raise Exception('All paths must have a unique final directory name if basepath is none')
 2322             rootdir = None
 2323         logger.debug("Rootdir is: %s", rootdir)
 2324     except Exception as e:
 2325         logger.critical("Unable to initialize: %s", (str(e)))
 2326         exceptionLogger.log(e)
 2327         sys.exit(1)
 2328 
 2329     # determine mode:
 2330     localmode = pickMode()
 2331 
 2332     # Open the connection
 2333 
 2334     backend = None
 2335     backendThread = None
 2336     
 2337     # Create a scheduler thread, if need be
 2338     scheduler = ThreadedScheduler.ThreadedScheduler() if args.progress else None
 2339 
 2340     # Get the connection object
 2341     try:
 2342         if localmode:
 2343             (conn, backend, backendThread) = runBackend(jobname)
 2344         else:
 2345             conn = getConnection(server, port)
 2346 
 2347         startBackup(name, args.priority, args.client, auto, args.force, args.full, args.create, password)
 2348     except Exception as e:
 2349         logger.critical("Unable to start session with %s:%s: %s", server, port, str(e))
 2350         exceptionLogger.log(e)
 2351         sys.exit(1)
 2352     if verbosity or args.stats or args.report != 'none':
 2353         logger.log(logging.STATS, "Name: {} Server: {}:{} Session: {}".format(backupName, server, port, sessionid))
 2354 
 2355 
 2356 
 2357     # Initialize the progress bar, if requested
 2358     if args.progress:
 2359         statusBar = initProgressBar(scheduler)
 2360 
 2361     if scheduler:
 2362         scheduler.start()
 2363 
 2364     # Send a command line
 2365     clHash = crypt.getHash()
 2366     clHash.update(bytes(commandLine, 'utf8'))
 2367     h = clHash.hexdigest()
 2368     encrypt, iv = makeEncryptor()
 2369     if iv is None:
 2370         iv = b''
 2371     data = iv + encrypt.encrypt(bytes(commandLine, 'utf8')) + encrypt.finish() + encrypt.digest()
 2372 
 2373     message = {
 2374         'message': 'COMMANDLINE',
 2375         'hash': h,
 2376         'line': data,
 2377         'size': len(commandLine),
 2378         'encrypted': True if iv else False
 2379     }
 2380     batchMessage(message)
 2381 
 2382     # Send the full configuration, if so desired.
 2383     if args.sendconfig:
 2384         a = vars(args)
 2385         a['directories'] = directories
 2386         if a['password']:
 2387             a['password'] = '-- removed --'
 2388         jsonArgs = json.dumps(a, cls=Util.ArgJsonEncoder, sort_keys=True)
 2389         message = {
 2390             "message": "CLICONFIG",
 2391             "args":    jsonArgs
 2392         }
 2393         batchMessage(message)
 2394 
 2395     # Now, do the actual work here.
 2396     exc = None
 2397     try:
 2398         # Now, process all the actual directories
 2399         for directory in directories:
 2400             # skip if already processed.
 2401             if directory in processedDirs:
 2402                 continue
 2403             # Create the fake directory entry(s) for this.
 2404             if rootdir:
 2405                 createPrefixPath(rootdir, directory)
 2406                 root = rootdir
 2407             else:
 2408                 (root, name) = os.path.split(directory)
 2409                 f = mkFileInfo(FakeDirEntry(root, name))
 2410                 sendDirEntry(0, 0, [f])
 2411             # And run the directory
 2412             recurseTree(directory, root, depth=args.maxdepth, excludes=globalExcludes)
 2413 
 2414         # If any metadata, clone or batch requests still lying around, send them now
 2415         if newmeta:
 2416             batchMessage(makeMetaMessage())
 2417         flushClones()
 2418         while flushBatchMsgs():
 2419             pass
 2420 
 2421         # Send a purge command, if requested.
 2422         if args.purge:
 2423             if args.purgetime:
 2424                 sendPurge(False)
 2425             else:
 2426                 sendPurge(True)
 2427     except KeyboardInterrupt as e:
 2428         logger.warning("Backup Interupted")
 2429         exc = "Backup Interrupted"
 2430         #exceptionLogger.log(e)
 2431     except ExitRecursionException as e:
 2432         root = e.rootException
 2433         logger.error("Caught exception: %s, %s", root.__class__.__name__, root)
 2434         exc = str(e)
 2435         #exceptionLogger.log(root)
 2436     except Exception as e:
 2437         logger.error("Caught exception: %s, %s", e.__class__.__name__, e)
 2438         exc = str(e)
 2439         exceptionLogger.log(e)
 2440     finally:
 2441         setProgress("Finishing backup", "")
 2442         conn.close(exc)
 2443         if localmode:
 2444             conn.send(Exception("Terminate connection"))
 2445 
 2446 
 2447     if localmode:
 2448         logger.info("Waiting for server to complete")
 2449         backendThread.join()        # Should I do communicate?
 2450 
 2451     endtime = datetime.datetime.now()
 2452 
 2453     if args.sanity:
 2454         # Sanity checks.  Enable for debugging.
 2455         if len(cloneContents) != 0:
 2456             logger.warning("Some cloned directories not processed: %d", len(cloneContents))
 2457             for key in cloneContents:
 2458                 (path, files) = cloneContents[key]
 2459                 print("{}:: {}".format(path, len(files)))
 2460 
 2461         # This next one is usually non-zero, for some reason.  Enable to debug.
 2462         #if len(inodeDB) != 0:
 2463             #logger.warning("%d InodeDB entries not processed", len(inodeDB))
 2464             #for key in list(inodeDB.keys()):
 2465                 #(_, path) = inodeDB[key]
 2466                 #print("{}:: {}".format(key, path))
 2467 
 2468     if args.progress:
 2469         statusBar.shutdown()
 2470 
 2471     # Print stats and files report
 2472     if args.stats:
 2473         printStats(starttime, endtime)
 2474     if args.report != 'none':
 2475         printReport(args.report)
 2476 
 2477     print('')
 2478 
 2479 if __name__ == '__main__':
 2480     sys.exit(main())