changeset
Made combination error-state into an error-state matrix, as well as Enum
Wed, 24 Jan 2018 20:18:45 +0000
- author
- Tuomo Valkonen <tuomov@iki.fi>
- date
- Wed, 24 Jan 2018 20:18:45 +0000
- changeset 61
- bc6c3d74e6ea
- parent 60
- 10bd7e3906d9
- child 62
- b7d13b2ad67e
Made combination error-state into an error-state matrix, as well as Enum
| backup.py | file | annotate | diff | comparison | revisions | |
| ui.py | file | annotate | diff | comparison | revisions |
--- a/backup.py Wed Jan 24 09:19:42 2018 +0000 +++ b/backup.py Wed Jan 24 20:18:45 2018 +0000 @@ -8,30 +8,41 @@ import keyring import borgend import repository +from enum import IntEnum from instance import BorgInstance from threading import Thread, Lock, Condition from scheduler import TerminableThread logger=borgend.logger.getChild(__name__) -# State -INACTIVE=0 -SCHEDULED=1 -QUEUED=2 -ACTIVE=3 -BUSY=4 -OFFLINE=5 -ERRORS=6 +class State(IntEnum): + # State + INACTIVE=0 + SCHEDULED=1 + QUEUED=2 + ACTIVE=3 + + +class Errors(IntEnum): + OK=0 + BUSY=1 + OFFLINE=2 + ERRORS=3 -def combine_state(state1, state2): - return max(state1, state2) + def combine(self, other): + return max(self, other) + + def ok(self): + return self==self.OK -loglevel_translation={ - 'CRITICAL': logging.CRITICAL, - 'ERROR': logging.ERROR, - 'WARNING': logging.WARNING, - 'DEBUG': logging.DEBUG, - 'INFO': logging.INFO + def __str__(self): + return _errorstring[self] + +_errorstring={ + Errors.OK: 'ok', + Errors.BUSY: 'busy', + Errors.OFFLINE: 'offline', + Errors.ERRORS: 'errors' } def translate_loglevel(x): @@ -47,6 +58,13 @@ return tmp return None +loglevel_translation={ + 'CRITICAL': logging.CRITICAL, + 'ERROR': logging.ERROR, + 'WARNING': logging.WARNING, + 'DEBUG': logging.DEBUG, + 'INFO': logging.INFO +} class Backup(TerminableThread): @@ -135,7 +153,8 @@ self.current_operation=None self.scheduled_operation=None self.lastrun_when=None - self.state=INACTIVE + self.state=State.INACTIVE + self.errors=Errors.OK self.__decode_config(cfg) @@ -162,16 +181,16 @@ def __log_listener(self): self.logger.debug('Log listener thread waiting for entries') success=True - for status in iter(self.borg_instance.read_log, None): - self.logger.debug(str(status)) - t=status['type'] + for msg in iter(self.borg_instance.read_log, None): + self.logger.debug(str(msg)) + t=msg['type'] - errors_this_message=None + errormsg=None callback=None if t=='progress_percent': - current=safe_get_int(status, 'current') - total=safe_get_int(status, 'total') + current=safe_get_int(msg, 'current') + total=safe_get_int(msg, 'total') if current is not None and total is not None: with self._cond: self.current_operation['progress_current']=current @@ -179,9 +198,9 @@ status, callback=self.__status_unlocked() elif t=='archive_progress': - original_size=safe_get_int(status, 'original_size') - compressed_size=safe_get_int(status, 'compressed_size') - deduplicated_size=safe_get_int(status, 'deduplicated_size') + original_size=safe_get_int(msg, 'original_size') + compressed_size=safe_get_int(msg, 'compressed_size') + deduplicated_size=safe_get_int(msg, 'deduplicated_size') if original_size is not None and original_size is not None and deduplicated_size is not None: with self._cond: self.current_operation['original_size']=original_size @@ -196,30 +215,30 @@ pass elif t=='log_message': - if 'levelname' not in status: - status['levelname']='ERROR' - if 'message' not in status: - status['message']='UNKNOWN' - if 'name' not in status: - status['name']='borg' - lvl=translate_loglevel(status['levelname']) - self.logger.log(lvl, status['name'] + ': ' + status['message']) + if 'levelname' not in msg: + msg['levelname']='ERROR' + if 'message' not in msg: + msg['message']='UNKNOWN' + if 'name' not in msg: + msg['name']='borg' + lvl=translate_loglevel(msg['levelname']) + self.logger.log(lvl, msg['name'] + ': ' + msg['message']) if lvl>=logging.WARNING: - errors_this_message=status - state=ERRORS - if ('msgid' in status and - (status['msgid']=='LockTimeout' or # observed in reality - status['msgid']=='LockErrorT' or # in docs - status['msgid']=='LockErrorT')): # in docs - state=BUSY + errormsg=msg + errors=Errors.ERRORS + if ('msgid' in msg and + (msg['msgid']=='LockTimeout' or # observed in reality + msg['msgid']=='LockErrorT' or # in docs + msg['msgid']=='LockErrorT')): # in docs + errors=Errors.BUSY with self._cond: - self.state=combine_state(self.state, state) + self.errors=self.errors.combine(errors) status, callback=self.__status_unlocked() else: self.logger.debug('Unrecognised log entry %s' % str(status)) if callback: - callback(status, errors=errors_this_message) + callback(status, errors=errormsg) self.logger.debug('Waiting for borg subprocess to terminate in log thread') @@ -228,12 +247,6 @@ self.logger.debug('Borg subprocess terminated; terminating log listener thread') def __result_listener(self): - # self.state=ACTIVE - # with self._cond: - # status, callback=self.__status_unlocked() - # if callback: - # callback(status) - self.logger.debug('Result listener thread waiting for result') res=self.borg_instance.read_result() @@ -242,25 +255,23 @@ self.thread_log.join() with self._cond: - state=self.state - - # If there were no errors, reset back to INACTIVE state - if state==ACTIVE: - state=INACTIVE + errors=self.errors self.logger.debug('Borg result: %s' % str(res)) - if res is None and state==INACTIVE: + if res is None: self.logger.error('No result from borg despite no error in log') - state=ERRORS + if errors.ok(): + errors=Errors.ERRORS self.logger.debug('Waiting for borg subprocess to terminate in result thread') if not self.borg_instance.wait(): self.logger.error('Borg subprocess did not terminate') - state=combine_state(state, ERRORS) + if errors.ok(): + errors=Errors.ERRORS - self.logger.debug('Borg subprocess terminated (end state %s); terminating result listener thread' % str(state)) + self.logger.debug('Borg subprocess terminated (errors state: %s); terminating result listener thread' % str(errors)) with self._cond: if self.current_operation['operation']=='create': @@ -269,7 +280,8 @@ self.thread_log=None self.borg_instance=None self.current_operation=None - self.state=state + self.state=State.INACTIVE + self.errors=errors self.__update_status() self._cond.notify() @@ -313,6 +325,7 @@ else: raise NotImplementedError("Invalid operation '%s'" % op['operation']) + # This must be called with self._cond held. def __launch_check(self): op=self.scheduled_operation if not op: @@ -324,7 +337,9 @@ self.current_operation=op self.current_operation['when_monotonic']=time.monotonic() - self.state=ACTIVE + self.state=State.ACTIVE + # Reset error status when starting a new operation + self.errors=Errors.OK self.__update_status() @@ -339,9 +354,10 @@ self.__main_thread_queue_and_launch() except Exception as err: self.logger.exception("Error with backup '%s'" % self._name) - self.lastrun_when=time.monotonic() - self.state=ERRORS - self.scheduled_operation=None + self.errors=Errors.ERRORS + + self.state=State.INACTIVE + self.scheduled_operation=None # Clean up to terminate: kill borg instance and communication threads if self.borg_instance: @@ -351,6 +367,8 @@ # Store threads to use outside lock thread_log=self.thread_log thread_res=self.thread_res + self.thread_log=None + self.thread_res=None self.logger.debug("Waiting for log and result threads to terminate") @@ -380,14 +398,18 @@ (op['operation'], op['detail'], delay)) self.scheduled_operation=op - self.state=combine_state(self.state, SCHEDULED) + self.state=State.SCHEDULED self.__update_status() # Wait under scheduled wait self.scheduler.wait_until(now+delay, self._cond, self._name) else: # Nothing scheduled - just wait - self.logger.debug("Waiting for manual scheduling") + self.logger.info("Waiting for manual scheduling") + + self.state=State.INACTIVE + self.__update_status() + self._cond.wait() # Main thread/3. If there is a scheduled operation (it might have been @@ -397,7 +419,7 @@ def __main_thread_queue_and_launch(self): if self.scheduled_operation: self.logger.debug("Queuing") - self.state=combine_state(self.state, QUEUED) + self.state=State.QUEUED self.__update_status() self.repository.queue_action(self._cond, action=self.__launch_check, @@ -416,7 +438,7 @@ return {'operation': 'create', 'detail': 'initial', 'when_monotonic': now+initial_interval} - elif self.state>=BUSY: + elif not self.errors.ok(): if self.retry_interval==0: return None else: @@ -436,20 +458,14 @@ if self.current_operation: status=self.current_operation - status['type']='current' - # Errors should be set by listeners + elif self.scheduled_operation: + status=self.scheduled_operation else: - if self.scheduled_operation: - status=self.scheduled_operation - if self.state==QUEUED: - status['type']='queued' - else: - status['type']='scheduled' - else: - status={'type': 'nothing'} + status={'type': 'nothing'} status['name']=self._name status['state']=self.state + status['errors']=self.errors if 'detail' not in status: status['detail']='NONE'
--- a/ui.py Wed Jan 24 09:19:42 2018 +0000 +++ b/ui.py Wed Jan 24 20:18:45 2018 +0000 @@ -14,26 +14,32 @@ logger=borgend.logger.getChild(__name__) -traynames={ - backup.INACTIVE: 'B.', - backup.SCHEDULED: 'B.', - backup.QUEUED: 'B:', - backup.ACTIVE: 'B!', - backup.BUSY: 'B⦙', - backup.OFFLINE: 'B⦙', - backup.ERRORS: 'B?' +traynames_ok={ + backup.State.INACTIVE: 'B.', + backup.State.SCHEDULED: 'B.', + backup.State.QUEUED: 'B:', + backup.State.ACTIVE: 'B!', } -statestring={ - backup.INACTIVE: 'inactive', - backup.SCHEDULED: 'scheduled', - backup.QUEUED: 'queued', - backup.ACTIVE: 'active', - backup.BUSY: 'busy', - backup.OFFLINE: 'offline', - backup.ERRORS: 'errors' +traynames_errors={ + # The first one should never be used + backup.Errors.OK: traynames_ok[backup.State.INACTIVE], + backup.Errors.BUSY: 'B⦙', + backup.Errors.OFFLINE: 'B⦙', + backup.Errors.ERRORS: 'B?' } +def trayname(ste): + state=ste[0] + errors=ste[1] + if not errors.ok(): + return traynames_errors[errors] + else: + return traynames_ok[state] + +def combine_state(a, b): + return (max(a[0], b[0]), max(a[1], b[1])) + # Refresh the menu at most once a second to reduce flicker refresh_interval=1.0 @@ -70,9 +76,19 @@ return '{0:.2f}TB'.format(B/TB) def make_title(status): - state=status['state'] - detail='' - if status['type']=='scheduled': + def add_detail(detail, new): + if detail: + return "%s; %s" % (detail, new) + else: + return new + + errors=status['errors'] + detail=None + + if not errors.ok(): + detail=add_detail(detail, str(errors)) + + if status['state']==backup.State.SCHEDULED: # Operation scheduled when=status['when'] now=time.time() @@ -91,15 +107,17 @@ twhen=time.localtime(when+30) whenstr='at %02d:%02d' % (twhen.tm_hour, twhen.tm_min) - detail='' - if state>=backup.BUSY and state in statestring: - detail=statestring[state] + '; ' + this_detail='' if status['detail']!='normal': - detail=detail+status['detail']+' ' - title="%s (%s%s %s)" % (status['name'], detail, status['operation'], whenstr) - elif status['type']=='queued': - title="%s (queued)" % status['name'] - elif status['type']=='current': + this_detail=status['detail'] + ' ' + + when_how_sched= "%s%s %s" % (this_detail, status['operation'], whenstr) + + detail=add_detail(detail, when_how_sched) + + elif status['state']==backup.State.QUEUED: + detail=add_detail(detail, "queued") + elif status['state']==backup.State.ACTIVE: # Operation running progress='' if 'progress_current' in status and 'progress_total' in status: @@ -107,15 +125,19 @@ elif 'original_size' in status and 'deduplicated_size' in status: progress=' %s→%s' % (humanbytes(status['original_size']), humanbytes(status['deduplicated_size'])) - title="%s (running: %s%s)" % (status['name'], status['operation'], progress) - else: # status['type']=='nothing': - # Should be unscheduled, nothing running - detail='' - if state>=backup.BUSY and state in statestring: - detail=' (' + statestring[state] + ')' - title=status['name'] + detail + + howrunning = "running %s%s" % (status['operation'], progress) + + detail=add_detail(detail, howrunning) + else: + pass - return title, state + if detail: + title=status['name'] + ' (' + detail + ')' + else: + title=status['name'] + + return title, (status['state'], status['errors']) class BorgendTray(rumps.App): def __init__(self, backups): @@ -143,11 +165,11 @@ self.refresh_timer=None - super().__init__(traynames[state], menu=menu, quit_button=None) + super().__init__(trayname(state), menu=menu, quit_button=None) def __rebuild_menu(self): menu=[] - state=backup.INACTIVE + state=(backup.State.INACTIVE, backup.Errors.OK) for index in range(len(self.backups)): b=self.backups[index] title, this_state=make_title(self.statuses[index]) @@ -156,12 +178,12 @@ # fixes this brain damage cbm=lambda sender, _b=b: self.__menu_select_backup(sender, _b) item=rumps.MenuItem(title, callback=cbm) - if this_state==backup.SCHEDULED: + if not this_state[1].ok(): + item.state=-1 + elif this_state[0]==backup.State.SCHEDULED or this_state[0]==backup.State.QUEUED: item.state=1 - elif this_state>=backup.BUSY: - item.state=-1 menu.append(item) - state=backup.combine_state(state, this_state) + state=combine_state(state, this_state) menu_log=rumps.MenuItem("Show log", callback=lambda _: showlog()) menu.append(menu_log) @@ -176,10 +198,10 @@ with self.lock: self.refresh_timer=None logger.debug('Rebuilding menu') - menu, active=self.__rebuild_menu() + menu, state=self.__rebuild_menu() self.menu.clear() self.menu.update(menu) - self.title=traynames[active] + self.title=trayname(state) def __status_callback(self, index, status, errorlog=None): logger.debug('Status callback: %s' % str(status))
