Skip to content
This repository

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP
branch: master
Fetching contributors…

Cannot retrieve contributors at this time

executable file 405 lines (342 sloc) 15.529 kb
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391 392 393 394 395 396 397 398 399 400 401 402 403 404 405
#!/usr/bin/python -W ignore::DeprecationWarning
# A BackupPC script to archive a host's files to Amazon S3.
#
# Point $Conf{ArchiveClientCmd} at me.
# Requires python-boto
#
# Usage: BackupPC_archiveHost tarCreatePath splitPath parPath host bkupNum \
# compPath fileExt splitSize outLoc parFile share
#
# Create secrets.py such that it has:
# accesskey = 'amazon aws access key'
# sharedkey = 'amazon aws shared key'
# gpgsymmetrickey = 'gpg symmetric key -- make it good, but do not lose it'
#
# Copyright (c) 2009-2011 Ryan S. Tucker
#
# Permission is hereby granted, free of charge, to any person obtaining a copy
# of this software and associated documentation files (the "Software"), to deal
# in the Software without restriction, including without limitation the rights
# to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
# copies of the Software, and to permit persons to whom the Software is
# furnished to do so, subject to the following conditions:
#
# The above copyright notice and this permission notice shall be included in
# all copies or substantial portions of the Software.
#
# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
# OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
# THE SOFTWARE.

import glob
import hashlib
import os
import socket
import sys
import time

from multiprocessing import Process, Queue, cpu_count
from subprocess import *

from boto.s3.connection import S3Connection
from boto.s3.key import Key
import boto.exception

import logging
import logging.handlers

import secrets

logger = logging.getLogger(__name__)

sysloghandler = logging.handlers.SysLogHandler('/dev/log',
                facility=logging.handlers.SysLogHandler.LOG_DAEMON)
syslogformatter = logging.Formatter('%(filename)s: %(levelname)s: %(message)s')
sysloghandler.setFormatter(syslogformatter)
logger.addHandler(sysloghandler)

consolehandler = logging.StreamHandler(sys.stdout)
consoleformatter = logging.Formatter('%(asctime)s: %(levelname)s: %(message)s')
consolehandler.setFormatter(consoleformatter)
logger.addHandler(consolehandler)

logger.setLevel(logging.DEBUG)

class VerifyError(Exception):
    pass

def is_exe(fpath):
    return os.path.exists(fpath) and os.access(fpath, os.X_OK)

def encrypt_file(filename, key, compress='/bin/cat'):
    compressmap = {'cat': 'none', 'gzip': 'ZLIB', 'bzip2': 'BZIP2'}
    if os.path.basename(compress) in compressmap.keys():
        compress_algo = compressmap[os.path.basename(compress)]
    else:
        compress_algo = 'none'

    cmd = ['/usr/bin/gpg', '--batch', '--no-tty']
    cmd.extend(['--compress-algo', compress_algo])
    cmd.extend(['--output', '%s.gpg' % filename])
    cmd.extend(['--passphrase-fd', '0'])
    cmd.extend(['--symmetric', filename])

    if is_exe(cmd[0]):
        logger.debug('encrypt_file: encrypting %s (compression: %s)' % (filename, compress_algo))
    else:
        raise RuntimeError('%s is not an executable file!' % cmd[0])

    proc = Popen(cmd, preexec_fn=lambda : os.nice(10), stdin=PIPE, stdout=PIPE)
    proc.communicate(key)

    if os.path.exists(filename + '.gpg'):
        oldfilesize = os.path.getsize(filename)
        newfilesize = os.path.getsize(filename + '.gpg')
        compressed = ((oldfilesize - newfilesize) / float(oldfilesize)) * 100
        logger.debug('encrypt_file: %s %s by %.2f%% (%i -> %i bytes)' % (filename, 'shrunk' if oldfilesize>newfilesize else 'grew', compressed, oldfilesize, newfilesize))
        return filename + '.gpg'
    else:
        raise RuntimeError('output file does not exist: %s.gpg' % filename)

def open_s3(accesskey, sharedkey, host):
    conn = S3Connection(accesskey, sharedkey, is_secure=True)
    mybucketname = (accesskey + '-bkup-' + host).lower()
    try:
        bucket = conn.get_bucket(mybucketname)
    except boto.exception.S3ResponseError:
        logger.info('open_s3: creating new bucket %s' % mybucketname)
        bucket = conn.create_bucket(mybucketname)
    bucket.set_acl('private')
    return bucket

def handle_progress(transmitted, pending):
    logger.debug("send_file: %i of %i bytes transmitted (%.2f%%)", transmitted, pending, (transmitted/float(pending))*100)

def verify_file(bucket, filename):
    "Returns True if the file size and md5sum match, False otherwise"
    basefilename = os.path.basename(filename)
    key = bucket.get_key(basefilename)
    stat = os.stat(filename)
    if key:
        if key.size == stat[6]:
            fp = open(filename)
            local_md5 = hashlib.md5(fp.read())
            fp.close()
            logger.debug('verify_file: %s: local md5 "%s", etag %s', filename, local_md5.hexdigest(), key.etag)
            if '"%s"' % local_md5.hexdigest() == key.etag:
                return True
    return False

def send_file(bucket, filename):
    basefilename = os.path.basename(filename)
    k = Key(bucket)
    k.key = basefilename

    if k.exists():
        if verify_file(bucket, filename):
            logger.warning("send_file: %s already exists and is identical, not overwriting", basefilename)
            return k
        logger.warning("send_file: %s already exists on S3, overwriting", basefilename)

    k.set_contents_from_filename(filename, cb=handle_progress, reduced_redundancy=True)

    logger.debug("send_file: %s sent, verifying fidelity", filename)
    if not verify_file(bucket, filename):
        raise VerifyError("verify failed")
    return k

def encryption_worker(in_q, out_q, unlink_q):
    "Encrypts things from the in_q, puts them in the out_q"
    start_time = time.time()
    counter = 0
    for filename, gpgkey, comppath in iter(in_q.get, 'STOP'):
        counter += 1
        cryptstart_time = time.time()
        logger.info("encryption_worker: encrypting %s", filename)
        result = encrypt_file(filename, gpgkey, comppath)
        out_q.put(result)
        unlink_q.put(filename)
        logger.debug("encryption_worker: encrypted %s in %i seconds", filename, time.time()-cryptstart_time)
    logger.debug("encryption_worker: queue is empty, terminating after %i items in %i seconds", counter, time.time()-start_time)
    time.sleep(5) # settle

def sending_worker(in_q, out_q, accesskey, sharedkey, host):
    "Sends things from the in_q using the send_file method"
    start_time = time.time()
    counter = 0
    for filename in iter(in_q.get, 'STOP'):
        sending_start = time.time()
        counter += 1
        retry_count = 0
        max_retries = 10
        done = False

        while retry_count <= max_retries and not done:
            try:
                logger.info("sending_worker: sending %s", filename)
                bucket = open_s3(accesskey, sharedkey, host)
                key = send_file(bucket, filename)
                key.set_acl('private')
                key.close()
                done = True
            except (boto.exception.S3ResponseError, socket.error, VerifyError), e:
                retry_count += 1
                sleeptime = 2**retry_count
                logger.error('sending_worker: exception %s, retrying in %i seconds (%i/%i)', e, sleeptime, retry_count, max_retries)
                time.sleep(sleeptime)

        if not done:
            # trip out
            logger.error('sending_worker: could not upload %s in %i retries', filename, retry_count)
        else:
            size = os.path.getsize(filename)
            sending_seconds = time.time() - sending_start
            bytespersecond = size / sending_seconds
            logger.debug("sending_worker: sent %s in %i seconds at %i bytes/second.", filename, sending_seconds, bytespersecond)
            out_q.put(filename)

    logger.debug("sending_worker: queue is empty, terminating after %i items in %i seconds", counter, time.time() - start_time)
    time.sleep(5) # settle

def unlink_worker(in_q):
    start_time = time.time()
    counter = 0
    for filename in iter(in_q.get, 'STOP'):
        counter += 1
        logger.debug("unlink_worker: deleting %s", filename)
        try:
            os.unlink(filename)
        except OSError, e:
            logger.warning("unlink_worker: caught exception: %s", e)

    logger.debug("unlink_worker: queue is empty, terminating after %i items in %i seconds", counter, time.time() - start_time)
    time.sleep(5) # settle

if __name__ == '__main__':
    # Read in arguments, verify that they match the BackupPC standard exactly
    if len(sys.argv) != 12:
        sys.stderr.write("Usage: %s tarCreatePath splitPath parPath host bkupNum compPath fileExt splitSize outLoc parFile share\n" % sys.argv[0])
        sys.exit(1)
    else:
        tarCreate = sys.argv[1]
        splitPath = sys.argv[2]
        parPath = sys.argv[3]
        host = sys.argv[4]
        bkupNum = int(sys.argv[5])
        compPath = sys.argv[6]
        fileExt = sys.argv[7]
        splitSize = int(sys.argv[8])
        outLoc = sys.argv[9]
        parfile = sys.argv[10]
        share = sys.argv[11]

    for i in [tarCreate, compPath, splitPath, parPath]:
        if i is not '' and not is_exe(i):
            sys.stderr.write('Error: %s is not an executable program\n' % i)
            sys.exit(1)

    beginning = time.time()

    # Create queues for workers
    gpg_queue = Queue()
    send_queue = Queue()
    unlink_queue = Queue()

    queues = {
        'gpg_queue': gpg_queue,
        'send_queue': send_queue,
        'unlink_queue': unlink_queue,
    }

    # Is there already evidence of this having been done before?
    if glob.glob('%s/%s.*.tar.*' % (outLoc, host)):
        logger.warning('main: finishing previous incomplete run')
        somefile = os.path.basename(glob.glob('%s/%s.*.tar.*' % (outLoc, host))[0])
        keyparts = somefile.split('.')
        encrypted = split = tarred = final = False
        if keyparts[-1] == 'gpg':
            keyparts.pop()
        if keyparts[-1] != 'tar' and len(keyparts[-1]) is 2:
            keyparts.pop()
        if keyparts[-1] == 'tar':
            keyparts.pop()

        bkupNum = int(keyparts.pop())

        filehead = '%s/%s.%i.tar.' % (outLoc, host, bkupNum)
        fileglob = filehead + '*'

        mesg = "Continuing upload for host %s, backup #%i" % (host, bkupNum)
        if splitSize > 0 and is_exe(splitPath):
            mesg += ', split into %i byte chunks' % splitSize
        if secrets.gpgsymmetrickey:
            mesg += ', encrypted with secret key'
        logger.info("main: %s", mesg)
    else:
        mesg = "Writing archive for host %s, backup #%i" % (host, bkupNum)

        tarcmd = [tarCreate, '-t']
        tarcmd.extend(['-h', host])
        tarcmd.extend(['-n', str(bkupNum)])
        tarcmd.extend(['-s', share])
        tarcmd.extend(['.'])

        splitcmd = None
        outfile = '%s/%s.%i.tar' % (outLoc, host, bkupNum)

        if splitSize > 0 and is_exe(splitPath):
            filehead = outfile + '.'
            fileglob = filehead + '*'
            splitcmd = [splitPath, '-b', str(splitSize), '-', filehead]
            mesg += ', split into %i byte chunks' % splitSize
        else:
            fileglob = outfile
            filehead = fileglob + '.'

        if secrets.gpgsymmetrickey:
            mesg += ', encrypted with secret key'

        logger.info("main: %s", mesg)
        logger.debug("main: executing tarcmd: %s > %s", ' '.join(tarcmd), outfile)

        tarfp = open(outfile, 'wb')
        proc = Popen(tarcmd, preexec_fn=lambda : os.nice(10), stdout=tarfp)
        proc.communicate()
        tarfp.close()

        if splitcmd:
            logger.debug("main: executing splitcmd: %s", ' '.join(splitcmd))
            tarfp = open(outfile, 'rb')
            proc = Popen(splitcmd, preexec_fn=lambda : os.nice(10), stdin=tarfp)
            proc.communicate()
            tarfp.close()
            unlink_queue.put(outfile)

    logger.info("main: dumped %i files from %s #%i" % (len(glob.glob(fileglob)), host, bkupNum))

    # Pre-run to check for artifacts
    for i in glob.glob(fileglob):
        if not i.endswith('.gpg') and os.path.exists(i + '.gpg'):
            logger.warning("main: orphaned GPG file being deleted: %s", i + '.gpg')
            os.unlink(i + '.gpg')

    # Run again to send files to the relevant queue
    for i in sorted(glob.glob(fileglob)):
        if secrets.gpgsymmetrickey and not i.endswith('.gpg'):
            # A tar file, unencrypted, needs encrypted.
            logger.debug("main: adding %s to gpg_queue", i)
            gpg_queue.put([i, secrets.gpgsymmetrickey, compPath])
        else:
            # either encryption is off, or the file is already encrypted
            logger.debug("main: adding %s to send_queue", i)
            send_queue.put(i)

    # Start some handlers, wait until everything is done
    try:
        process_count = cpu_count()
    except NotImplementedError:
        process_count = 1

    procs = []

    for i in range(process_count):
        p = Process(name="encryption_worker_%i" % i, target=encryption_worker, args=(gpg_queue, send_queue, unlink_queue))
        p.start()
        procs.append(p)

    send_p = Process(name="send_worker", target=sending_worker, args=(send_queue, unlink_queue, secrets.accesskey, secrets.sharedkey, host))
    send_p.start()
    procs.append(send_p)

    unlink_p = Process(name="unlink_worker", target=unlink_worker, args=(unlink_queue,))
    unlink_p.start()
    procs.append(unlink_p)

    send_queue_closed = False
    unlink_queue_closed = False

    # Put STOP command(s) at the end of the GPG queue.
    gpg_queue_closed = True
    for i in range(process_count):
        gpg_queue.put('STOP')

    for i in procs:
        # wait for each process to terminate in turn
        i.join()
        logger.debug("main: process terminated: %s", i.name)

        # count how many crypto processes are still running
        crypto_running = 0
        for j in procs:
            if j.name.startswith("encryption_worker") and j.is_alive():
                crypto_running += 1

        if crypto_running == 0 and not send_queue_closed:
            # crypto is done, close up the send queue
            logger.debug("main: queuing final file")
            finalfile = '%sCOMPLETE' % filehead
            fp = open(finalfile, 'w')
            fp.write('%s %s "%s"' % (beginning, time.time(), mesg))
            fp.close()
            send_queue.put(finalfile)

            logger.debug("main: queuing stop sentinel for send_queue")
            send_queue.put('STOP')
            send_queue_closed = True

        if not send_p.is_alive() and not unlink_queue_closed:
            # sending is done, close up the unlink queue
            logger.debug("main: queuing stop sentinel for unlink_queue")
            unlink_queue.put('STOP')
            unlink_queue_closed = True

    for qname, q in queues.items():
        time.sleep(5) # settle
        if not q.empty():
            logger.critical("main: queue %s not empty!", qname)
            raise Exception("queue not empty: %s" % qname)
        else:
            logger.debug("main: queue %s is empty", qname)

    logger.info("main: completed run after %i seconds", (time.time() - beginning))
Something went wrong with that request. Please try again.