# -*- Mode:Python; indent-tabs-mode:nil; tab-width:4 -*-
#
# Copyright 2002 Ben Escoto <ben@emerose.org>
# Copyright 2007 Kenneth Loafman <kenneth@loafman.com>
# Copyright 2008 Michael Terry <mike@mterry.name>
# Copyright 2011 Canonical Ltd
#
# This file is part of duplicity.
#
# Duplicity is free software; you can redistribute it and/or modify it
# under the terms of the GNU General Public License as published by the
# Free Software Foundation; either version 2 of the License, or (at your
# option) any later version.
#
# Duplicity is distributed in the hope that it will be useful, but
# WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
# General Public License for more details.
#
# You should have received a copy of the GNU General Public License
# along with duplicity; if not, write to the Free Software Foundation,
# Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
"""Log various messages depending on verbosity level"""
import os
import sys
import logging
import datetime
MIN = 0
ERROR = 0
WARNING = 2
NOTICE = 3
INFO = 5
DEBUG = 9
MAX = 9
_logger = None
[docs]def DupToLoggerLevel(verb):
"""Convert duplicity level to the logging module's system, where higher is
more severe"""
return MAX - verb + 1
[docs]def LoggerToDupLevel(verb):
"""Convert logging module level to duplicity's system, where lowere is
more severe"""
return DupToLoggerLevel(verb)
[docs]def LevelName(level):
if level >= 9:
return "DEBUG"
elif level >= 5:
return "INFO"
elif level >= 3:
return "NOTICE"
elif level >= 1:
return "WARNING"
else:
return "ERROR"
[docs]def Log(s, verb_level, code=1, extra=None, force_print=False):
"""Write s to stderr if verbosity level low enough"""
global _logger
if extra:
controlLine = '%d %s' % (code, extra)
else:
controlLine = '%d' % (code)
if not s:
s = '' # If None is passed, standard logging would render it as 'None'
if force_print:
initial_level = _logger.getEffectiveLevel()
_logger.setLevel(DupToLoggerLevel(MAX))
# If all the backends kindly gave us unicode, we could enable this next
# assert line. As it is, we'll attempt to convert s to unicode if we
# are handed bytes. One day we should update the backends.
# assert isinstance(s, unicode)
if not isinstance(s, unicode):
s = s.decode("utf8", "replace")
_logger.log(DupToLoggerLevel(verb_level), s,
extra={'levelName': LevelName(verb_level),
'controlLine': controlLine})
if force_print:
_logger.setLevel(initial_level)
[docs]def Debug(s):
"""Shortcut used for debug message (verbosity 9)."""
Log(s, DEBUG)
[docs]class InfoCode:
"""Enumeration class to hold info code values.
These values should never change, as frontends rely upon them.
Don't use 0 or negative numbers."""
generic = 1
progress = 2
collection_status = 3
diff_file_new = 4
diff_file_changed = 5
diff_file_deleted = 6
patch_file_writing = 7
patch_file_patching = 8
# file_list = 9 # 9 isn't used anymore. It corresponds to an older syntax for listing files
file_list = 10
synchronous_upload_begin = 11
asynchronous_upload_begin = 12
synchronous_upload_done = 13
asynchronous_upload_done = 14
skipping_socket = 15
upload_progress = 16
[docs]def Info(s, code=InfoCode.generic, extra=None):
"""Shortcut used for info messages (verbosity 5)."""
Log(s, INFO, code, extra)
[docs]def Progress(s, current, total=None):
"""Shortcut used for progress messages (verbosity 5)."""
if total:
controlLine = '%d %d' % (current, total)
else:
controlLine = '%d' % current
Log(s, INFO, InfoCode.progress, controlLine)
def _ElapsedSecs2Str(secs):
tdelta = datetime.timedelta(seconds=secs)
hours, rem = divmod(tdelta.seconds, 3600)
minutes, seconds = divmod(rem, 60)
fmt = ""
if tdelta.days > 0:
fmt = "%dd," % (tdelta.days)
fmt = "%s%02d:%02d:%02d" % (fmt, hours, minutes, seconds)
return fmt
def _RemainingSecs2Str(secs):
tdelta = datetime.timedelta(seconds=secs)
hours, rem = divmod(tdelta.seconds, 3600)
minutes, seconds = divmod(rem, 60)
fmt = ""
if tdelta.days > 0:
fmt = "%dd" % (tdelta.days)
if hours > 0:
fmt = "%s %dh" % (fmt, hours)
if minutes > 0:
fmt = "%s %dmin" % (fmt, minutes)
elif hours > 0:
fmt = "%dh" % hours
if minutes > 0:
fmt = "%s %dmin" % (fmt, minutes)
elif minutes > 5:
fmt = "%dmin" % minutes
elif minutes > 0:
fmt = "%dmin" % minutes
if seconds >= 30:
fmt = "%s 30sec" % fmt
elif seconds > 45:
fmt = "< 1min"
elif seconds > 30:
fmt = "< 45sec"
elif seconds > 15:
fmt = "< 30sec"
else:
fmt = "%dsec" % seconds
return fmt
[docs]def TransferProgress(progress, eta, changed_bytes, elapsed, speed, stalled):
"""Shortcut used for upload progress messages (verbosity 5)."""
dots = int(0.4 * progress) # int(40.0 * progress / 100.0) -- for 40 chars
data_amount = float(changed_bytes) / 1024.0
data_scale = "KB"
if data_amount > 1000.0:
data_amount /= 1024.0
data_scale = "MB"
if data_amount > 1000.0:
data_amount /= 1024.0
data_scale = "GB"
if stalled:
eta_str = "Stalled!"
speed_amount = 0
speed_scale = "B"
else:
eta_str = _RemainingSecs2Str(eta)
speed_amount = float(speed) / 1024.0
speed_scale = "KB"
if speed_amount > 1000.0:
speed_amount /= 1024.0
speed_scale = "MB"
if speed_amount > 1000.0:
speed_amount /= 1024.0
speed_scale = "GB"
s = "%.1f%s %s [%.1f%s/s] [%s>%s] %d%% ETA %s" % (data_amount, data_scale,
_ElapsedSecs2Str(elapsed),
speed_amount, speed_scale,
'=' * dots, ' ' * (40 - dots),
progress,
eta_str
)
controlLine = "%d %d %d %d %d %d" % (changed_bytes, elapsed, progress, eta, speed, stalled)
Log(s, NOTICE, InfoCode.upload_progress, controlLine)
[docs]def PrintCollectionStatus(col_stats, force_print=False):
"""Prints a collection status to the log"""
Log(unicode(col_stats), 8, InfoCode.collection_status,
'\n' + '\n'.join(col_stats.to_log_info()), force_print)
[docs]def PrintCollectionFileChangedStatus(col_stats, filepath, force_print=False):
"""Prints a collection status to the log"""
Log(unicode(col_stats.get_file_changed_record(filepath)), 8, InfoCode.collection_status, None, force_print)
[docs]def Notice(s):
"""Shortcut used for notice messages (verbosity 3, the default)."""
Log(s, NOTICE)
[docs]class WarningCode:
"""Enumeration class to hold warning code values.
These values should never change, as frontends rely upon them.
Don't use 0 or negative numbers."""
generic = 1
orphaned_sig = 2
unnecessary_sig = 3
unmatched_sig = 4
incomplete_backup = 5
orphaned_backup = 6
ftp_ncftp_v320 = 7 # moved from error
cannot_iterate = 8
cannot_stat = 9
cannot_read = 10
no_sig_for_time = 11
cannot_process = 12
process_skipped = 13
[docs]def Warn(s, code=WarningCode.generic, extra=None):
"""Shortcut used for warning messages (verbosity 2)"""
Log(s, WARNING, code, extra)
[docs]class ErrorCode:
"""Enumeration class to hold error code values.
These values should never change, as frontends rely upon them.
Don't use 0 or negative numbers. This code is returned by duplicity
to indicate which error occurred via both exit code and log."""
generic = 1 # Don't use if possible, please create a new code and use it
command_line = 2
hostname_mismatch = 3
no_manifests = 4
mismatched_manifests = 5
unreadable_manifests = 6
cant_open_filelist = 7
bad_url = 8
bad_archive_dir = 9
bad_sign_key = 10
restore_dir_exists = 11
verify_dir_doesnt_exist = 12
backup_dir_doesnt_exist = 13
file_prefix_error = 14
globbing_error = 15
redundant_inclusion = 16
inc_without_sigs = 17
no_sigs = 18
restore_dir_not_found = 19
no_restore_files = 20
mismatched_hash = 21
unsigned_volume = 22
user_error = 23
boto_old_style = 24
boto_lib_too_old = 25
boto_calling_format = 26
ftp_ncftp_missing = 27
ftp_ncftp_too_old = 28
# ftp_ncftp_v320 = 29 # moved to warning
exception = 30
gpg_failed = 31
s3_bucket_not_style = 32
not_implemented = 33
get_freespace_failed = 34
not_enough_freespace = 35
get_ulimit_failed = 36
maxopen_too_low = 37
connection_failed = 38
restart_file_not_found = 39
gio_not_available = 40
source_dir_mismatch = 42 # 41 is reserved for par2
ftps_lftp_missing = 43
volume_wrong_size = 44
enryption_mismatch = 45
pythonoptimize_set = 46
dpbx_nologin = 47
bad_request = 48
# 50->69 reserved for backend errors
backend_error = 50
backend_permission_denied = 51
backend_not_found = 52
backend_no_space = 53
backend_command_error = 54
backend_code_error = 55
# Reserve 126 because it is used as an error code for pkexec
# Reserve 127 because it is used as an error code for pkexec
# Reserve 255 because it is used as an error code for gksu
[docs]def Error(s, code=ErrorCode.generic, extra=None):
"""Write error message"""
Log(s, ERROR, code, extra)
[docs]def FatalError(s, code=ErrorCode.generic, extra=None):
"""Write fatal error message and exit"""
Log(s, ERROR, code, extra)
shutdown()
sys.exit(code)
[docs]class OutFilter(logging.Filter):
"""Filter that only allows warning or less important messages"""
[docs] def filter(self, record):
return record.msg and record.levelno <= DupToLoggerLevel(WARNING)
[docs]class ErrFilter(logging.Filter):
"""Filter that only allows messages more important than warnings"""
[docs] def filter(self, record):
return record.msg and record.levelno > DupToLoggerLevel(WARNING)
[docs]def setup():
"""Initialize logging"""
global _logger
if _logger:
return
_logger = logging.getLogger("duplicity")
# Default verbosity allows notices and above
setverbosity(NOTICE)
# stdout and stderr are for different logging levels
outHandler = logging.StreamHandler(sys.stdout)
outHandler.addFilter(OutFilter())
_logger.addHandler(outHandler)
errHandler = logging.StreamHandler(sys.stderr)
errHandler.addFilter(ErrFilter())
_logger.addHandler(errHandler)
[docs]class MachineFilter(logging.Filter):
"""Filter that only allows levels that are consumable by other processes."""
[docs] def filter(self, record):
# We only want to allow records that have our custom level names
return hasattr(record, 'levelName')
[docs]def add_fd(fd):
"""Add stream to which to write machine-readable logging"""
global _logger
handler = logging.StreamHandler(os.fdopen(fd, 'w'))
handler.setFormatter(MachineFormatter())
handler.addFilter(MachineFilter())
_logger.addHandler(handler)
[docs]def add_file(filename):
"""Add file to which to write machine-readable logging"""
global _logger
handler = logging.FileHandler(filename)
handler.setFormatter(MachineFormatter())
handler.addFilter(MachineFilter())
_logger.addHandler(handler)
[docs]def setverbosity(verb):
"""Set the verbosity level"""
global _logger
_logger.setLevel(DupToLoggerLevel(verb))
[docs]def getverbosity():
"""Get the verbosity level"""
global _logger
return LoggerToDupLevel(_logger.getEffectiveLevel())
[docs]def shutdown():
"""Cleanup and flush loggers"""
logging.shutdown()