# Back In Time
# Copyright (C) 2016-2022 Germar Reitze
#
# This program 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.
#
# This program is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
# GNU General Public License for more details.
#
# You should have received a copy of the GNU General Public License along
# with this program; if not, write to the Free Software Foundation, Inc.,
# 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
import os
import re
import logger
import snapshots
import tools
[docs]
class LogFilter(object):
"""
A Filter for snapshot logs which will both decode log lines and filter them
for the requested ``mode``.
Args:
mode (int): which filter should be used.
Possible values:
:py:data:`NO_FILTER`,
:py:data:`ERROR`,
:py:data:`CHANGES`,
:py:data:`INFORMATION` or
:py:data:`ERROR_AND_CHANGES`
decode (encfstools.Decode): instance used for decoding lines or ``None``
"""
# TODO Better use an enumeration
NO_FILTER = 0
ERROR = 1
CHANGES = 2
INFORMATION = 3
ERROR_AND_CHANGES = 4
RSYNC_TRANSFER_FAILURES = 5
# Regular expressions used for filtering log file lines.
# RegExp syntax see: https://docs.python.org/3.10/library/re.html#regular-expression-syntax
# (?:...) = the matched substring cannot be retrieved in a group (non-capturing)
REGEX = {None: None,
NO_FILTER: None,
ERROR: re.compile(r'^(?:\[E\]|[^\[])'),
CHANGES: re.compile(r'^(?:\[C\]|[^\[])'),
INFORMATION: re.compile(r'^(?:\[I\]|[^\[])'),
ERROR_AND_CHANGES: re.compile(r'^(?:\[E\]|\[C\]|[^\[])'),
RSYNC_TRANSFER_FAILURES: re.compile(
# All links to rsync's source reference the commit 2f9b963 from Jun 27, 2023 (most-recent commit on "master" as at Jan 28, 2024)
r'.*(?:'
r'Invalid cross-device link' # not directly contained in rsync's source code but may be caught and passed through as-is
r'|symlink has no referent' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1281
r'|readlink_stat\(.?\) failed' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1294
r'|link_stat .* failed' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1810
r'|receive_sums failed' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/sender.c#L347
r'|send_files failed to open' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/sender.c#L361
r'|fstat failed' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/sender.c#L373
r'|read errors mapping' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/sender.c#L435
r'|change_dir .* failed' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/main.c#L749
# https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/main.c#L807
# https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/main.c#L827
# https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/main.c#L1161
r'|skipping overly long name' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1247
r'|skipping file with bogus \(zero\) st_mode' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1300
r'|skipping symlink with 0-length value' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1569
r'|cannot convert filename' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L748
# https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1599
r'|cannot convert symlink data for' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1144
# https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1613
r'|opendir .* failed' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1842
r'|filename overflows max-path len by' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1868
r'|cannot send file with empty name in' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1876
r'|readdir\(.*\)' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L1888
r'|cannot add local filter rules in long-named directory' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/exclude.c#L817
r'|failed to re-read xattr' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/xattrs.c#L662
r'|Skipping sender remove of destination file' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/sender.c#L152
r'|Skipping sender remove for changed file' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/sender.c#L161
r'|could not make way for' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/delete.c#L220
r'|system says the ACL I packed is invalid' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/acls.c#L435
r'|recv_acl_access: value out of range' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/acls.c#L689
r'|recv_acl_index: .* ACL index' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/acls.c#L739
r'|Create time value of .* truncated on receiver' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L858
r'|FATAL I/O ERROR: dying to avoid a \-\-delete' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/flist.c#L2005
r'|IO error encountered' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/generator.c#L295
r'|some files/attrs were not transferred' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/log.c#L97
r'|temporary filename too long' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/receiver.c#L138
r'|No batched update for' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/receiver.c#L456
r'|recv_files: .* is a directory' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/receiver.c#L805
r'|no ftruncate for over-long pre-alloc' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/util1.c#L438
r'|daemon refused to receive' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/generator.c#L1270
r'|get_xattr_data: lgetxattr' # https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/xattrs.c#L199
# https://github.com/WayneD/rsync/blob/2f9b963abaa52e44891180fe6c0d1c2219f6686d/xattrs.c#L215
# r').*' # no need to match the remainder of the line
r')'
)}
def __init__(self, mode = 0, decode = None):
self.regex = self.REGEX[mode]
self.decode = decode
if decode:
self.header = (
'### This log has been decoded with automatic search pattern\n'
'### If some paths are not decoded you can manually decode '
'them with:\n'
'### \'backintime --quiet '
)
if int(decode.config.currentProfile()) > 1:
self.header += '--profile "%s" ' % decode.config.profileName()
self.header += '--decode <path>\'\n\n'
else:
self.header = ''
[docs]
def filter(self, line):
"""
Filter and decode ``line`` with predefined ``mode`` and
``decode`` instance.
Args:
line (str): log line read from disk
Returns:
str: decoded ``line`` or ``None`` if the line was filtered
"""
if not line:
#keep empty lines
return line
if self.regex and not self.regex.match(line):
return
if self.decode:
return self.decode.log(line)
else:
return line
[docs]
class SnapshotLog(object):
"""
Read and write Snapshot log to "~/.local/share/backintime/takesnapshot_<N>.log".
Where <N> is the profile ID ``profile``.
Args:
cfg (config.Config): current config
profile (int): profile that should be used to identify the log
"""
NONE = 0
ERRORS = 1
CHANGES_AND_ERRORS = 2
ALL = 3
def __init__(self, cfg, profile = None):
self.config = cfg
if profile:
self.profile = profile
else:
self.profile = cfg.currentProfile()
self.logLevel = cfg.logLevel()
self.logFileName = cfg.takeSnapshotLogFile(self.profile)
self.logFile = None
self.timer = tools.Alarm(self.flush, overwrite = False)
def __del__(self):
if self.logFile:
self.logFile.close()
[docs]
def get(self, mode = None, decode = None, skipLines = 0):
"""
Read the log, filter and decode it and yield its lines.
Args:
mode (int): Mode used for filtering. Take a look at
:py:class:`snapshotlog.LogFilter`
decode (encfstools.Decode): instance used for decoding lines or ``None``
skipLines (int): skip ``n`` lines before yielding lines.
This is used to append only new lines
to LogView
Yields:
str: filtered and decoded log lines
"""
logFilter = LogFilter(mode, decode)
count = logFilter.header.count('\n')
try:
with open(self.logFileName, 'rt') as f:
if logFilter.header and not skipLines:
yield logFilter.header
for line in f.readlines():
line = logFilter.filter(line.rstrip('\n'))
if not line is None:
count += 1
if count <= skipLines:
continue
yield line
except Exception as e:
msg = ('Failed to get take_snapshot log from {}:'.format(self.logFile), str(e))
logger.debug(' '.join(msg), self)
for line in msg:
yield line
[docs]
def new(self, date):
"""
Create a new log file or - if the last new_snapshot can be continued -
add a note to the current log.
Args:
date (datetime.datetime): current date
"""
if snapshots.NewSnapshot(self.config).saveToContinue:
msg = "Last snapshot didn't finish but can be continued.\n\n"
msg += "======== continue snapshot (profile %s): %s ========\n"
else:
if os.path.exists(self.logFileName):
if self.logFile:
self.logFile.close()
self.logFile = None
os.remove(self.logFileName)
msg = "========== Take snapshot (profile %s): %s ==========\n"
self.append(msg %(self.profile, date.strftime('%c')), 1)
[docs]
def append(self, msg, level):
"""
Append ``msg`` to the log if ``level`` is lower than configured log level.
Args:
msg (str): message line that should be added to the log
level (int): verbosity level of current line. msg will only be
added to log if level is lower than configured
log level :py:func:`config.Config.logLevel`.
Possible Values:
:py:data:`SnapshotLog.ERRORS`,
:py:data:`SnapshotLog.CHANGES_AND_ERRORS` or
:py:data:`SnapshotLog.ALL`
"""
if level > self.logLevel:
return
if not self.logFile:
self.logFile = open(self.logFileName, 'at')
self.logFile.write(msg + '\n')
self.timer.start(5) # flush the log output buffer after 5 seconds
[docs]
def flush(self):
"""
Write the in-memory buffer of the log output into the log file.
"""
if self.logFile:
try:
# TODO flush() does not necessarily write the file’s data to disk.
# Use flush() followed by os.fsync() to ensure this behavior.
# https://docs.python.org/2/library/stdtypes.html#file.flush
self.logFile.flush()
except RuntimeError as e:
# Fixes #1003 (RTE reentrant call inside io.BufferedWriter)
# This RTE will not be logged since this would be another reentrant call
pass