/mandos/trunk

To get this branch, use:
bzr branch http://bzr.recompile.se/loggerhead/mandos/trunk

« back to all changes in this revision

Viewing changes to mandos-monitor

  • Committer: Teddy Hogeborn
  • Date: 2023-02-07 23:03:33 UTC
  • Revision ID: teddy@recompile.se-20230207230333-5halrp7943pgb3w1
Server: Bug fix: Stagger checker runs when creating clients

* mandos (Client.enable()): Do not set self.expires here; move it to
  "init_checker".
  (Client.init_checker()): Take new "randomize_start" argument.  If
  True, randomize delay before starting checker.  Also, do not start
  checker right now, but instead extend expire time so that the
  scheduled checker always has time to run.
  (Checker.start_checker): Take new "start_was_randomized" argument.
  If True, reset scheduled checker runs to be 'interval' apart,
  instead of using the initial delay.  (Bug fix)
  (main): On startup, pass argument randomize_start=True to
  client.init_checker() when initizlizing checkers for all enabled
  clients.

Reported-by: Louis Charreau <Louis.Charreau@vadesecure.com>
Suggested-by: Louis Charreau <Louis.Charreau@vadesecure.com>
Fixes: 1200 ("Server: Stagger checker runs when creating clients")

Show diffs side-by-side

added added

removed removed

Lines of Context:
mandos-monitor
1
 
#!/usr/bin/python
 
1
#!/usr/bin/python3 -bbI
2
2
# -*- mode: python; coding: utf-8 -*-
3
3
#
4
4
# Mandos Monitor - Control and monitor the Mandos server
23
23
#
24
24
# Contact the authors at <mandos@recompile.se>.
25
25
#
26
 
 
27
26
from __future__ import (division, absolute_import, print_function,
28
27
                        unicode_literals)
 
28
 
29
29
try:
30
30
    from future_builtins import *
31
31
except ImportError:
32
32
    pass
33
33
 
34
34
import sys
 
35
import logging
35
36
import os
36
 
 
 
37
import warnings
37
38
import datetime
 
39
import locale
38
40
 
39
41
import urwid.curses_display
40
42
import urwid
44
46
 
45
47
import dbus
46
48
 
47
 
import locale
48
 
 
49
 
import logging
50
 
 
51
49
if sys.version_info.major == 2:
 
50
    __metaclass__ = type
52
51
    str = unicode
53
 
 
54
 
locale.setlocale(locale.LC_ALL, '')
55
 
 
56
 
logging.getLogger('dbus.proxies').setLevel(logging.CRITICAL)
 
52
    input = raw_input
 
53
 
 
54
# Show warnings by default
 
55
if not sys.warnoptions:
 
56
    warnings.simplefilter("default")
 
57
 
 
58
log = logging.getLogger(os.path.basename(sys.argv[0]))
 
59
logging.basicConfig(level="NOTSET", # Show all messages
 
60
                    format="%(message)s") # Show basic log messages
 
61
 
 
62
logging.captureWarnings(True)   # Show warnings via the logging system
 
63
 
 
64
locale.setlocale(locale.LC_ALL, "")
 
65
 
 
66
logging.getLogger("dbus.proxies").setLevel(logging.CRITICAL)
57
67
 
58
68
# Some useful constants
59
 
domain = 'se.recompile'
60
 
server_interface = domain + '.Mandos'
61
 
client_interface = domain + '.Mandos.Client'
62
 
version = "1.8.1"
 
69
domain = "se.recompile"
 
70
server_interface = domain + ".Mandos"
 
71
client_interface = domain + ".Mandos.Client"
 
72
version = "1.8.15"
63
73
 
64
74
try:
65
75
    dbus.OBJECT_MANAGER_IFACE
84
94
                             int(fraction*1000000))  # Microseconds
85
95
 
86
96
 
87
 
class MandosClientPropertyCache(object):
 
97
class MandosClientPropertyCache:
88
98
    """This wraps a Mandos Client D-Bus proxy object, caches the
89
99
    properties and calls a hook function when any of them are
90
100
    changed.
122
132
    """
123
133
 
124
134
    def __init__(self, server_proxy_object=None, update_hook=None,
125
 
                 delete_hook=None, logger=None, **kwargs):
 
135
                 delete_hook=None, **kwargs):
126
136
        # Called on update
127
137
        self.update_hook = update_hook
128
138
        # Called on delete
129
139
        self.delete_hook = delete_hook
130
140
        # Mandos Server proxy object
131
141
        self.server_proxy_object = server_proxy_object
132
 
        # Logger
133
 
        self.logger = logger
134
142
 
135
143
        self._update_timer_callback_tag = None
136
144
 
163
171
                                         self.rejected,
164
172
                                         client_interface,
165
173
                                         byte_arrays=True))
166
 
        self.logger('Created client {}'
167
 
                    .format(self.properties["Name"]), level=0)
 
174
        log.debug("Created client %s", self.properties["Name"])
168
175
 
169
176
    def using_timer(self, flag):
170
177
        """Call this method with True or False when timer should be
172
179
        """
173
180
        if flag and self._update_timer_callback_tag is None:
174
181
            # Will update the shown timer value every second
175
 
            self._update_timer_callback_tag = (GLib.timeout_add
176
 
                                               (1000,
177
 
                                                self.update_timer))
 
182
            self._update_timer_callback_tag = (
 
183
                GLib.timeout_add(1000,
 
184
                                 glib_safely(self.update_timer)))
178
185
        elif not (flag or self._update_timer_callback_tag is None):
179
186
            GLib.source_remove(self._update_timer_callback_tag)
180
187
            self._update_timer_callback_tag = None
181
188
 
182
189
    def checker_completed(self, exitstatus, condition, command):
183
190
        if exitstatus == 0:
184
 
            self.logger('Checker for client {} (command "{}")'
185
 
                        ' succeeded'.format(self.properties["Name"],
186
 
                                            command), level=0)
 
191
            log.debug('Checker for client %s (command "%s")'
 
192
                      " succeeded", self.properties["Name"], command)
187
193
            self.update()
188
194
            return
189
195
        # Checker failed
190
196
        if os.WIFEXITED(condition):
191
 
            self.logger('Checker for client {} (command "{}") failed'
192
 
                        ' with exit code {}'
193
 
                        .format(self.properties["Name"], command,
194
 
                                os.WEXITSTATUS(condition)))
 
197
            log.info('Checker for client %s (command "%s") failed'
 
198
                     " with exit code %d", self.properties["Name"],
 
199
                     command, os.WEXITSTATUS(condition))
195
200
        elif os.WIFSIGNALED(condition):
196
 
            self.logger('Checker for client {} (command "{}") was'
197
 
                        ' killed by signal {}'
198
 
                        .format(self.properties["Name"], command,
199
 
                                os.WTERMSIG(condition)))
 
201
            log.info('Checker for client %s (command "%s") was'
 
202
                     " killed by signal %d", self.properties["Name"],
 
203
                     command, os.WTERMSIG(condition))
200
204
        self.update()
201
205
 
202
206
    def checker_started(self, command):
203
207
        """Server signals that a checker started."""
204
 
        self.logger('Client {} started checker "{}"'
205
 
                    .format(self.properties["Name"],
206
 
                            command), level=0)
 
208
        log.debug('Client %s started checker "%s"',
 
209
                  self.properties["Name"], command)
207
210
 
208
211
    def got_secret(self):
209
 
        self.logger('Client {} received its secret'
210
 
                    .format(self.properties["Name"]))
 
212
        log.info("Client %s received its secret",
 
213
                 self.properties["Name"])
211
214
 
212
215
    def need_approval(self, timeout, default):
213
216
        if not default:
214
 
            message = 'Client {} needs approval within {} seconds'
 
217
            message = "Client %s needs approval within %f seconds"
215
218
        else:
216
 
            message = 'Client {} will get its secret in {} seconds'
217
 
        self.logger(message.format(self.properties["Name"],
218
 
                                   timeout/1000))
 
219
            message = "Client %s will get its secret in %f seconds"
 
220
        log.info(message, self.properties["Name"], timeout/1000)
219
221
 
220
222
    def rejected(self, reason):
221
 
        self.logger('Client {} was rejected; reason: {}'
222
 
                    .format(self.properties["Name"], reason))
 
223
        log.info("Client %s was rejected; reason: %s",
 
224
                 self.properties["Name"], reason)
223
225
 
224
226
    def selectable(self):
225
227
        """Make this a "selectable" widget.
251
253
        # Rebuild focus and non-focus widgets using current properties
252
254
 
253
255
        # Base part of a client. Name!
254
 
        base = '{name}: '.format(name=self.properties["Name"])
 
256
        base = "{name}: ".format(name=self.properties["Name"])
255
257
        if not self.properties["Enabled"]:
256
258
            message = "DISABLED"
257
259
            self.using_timer(False)
279
281
                timer = datetime.timedelta(0)
280
282
            else:
281
283
                expires = (datetime.datetime.strptime
282
 
                           (expires, '%Y-%m-%dT%H:%M:%S.%f'))
 
284
                           (expires, "%Y-%m-%dT%H:%M:%S.%f"))
283
285
                timer = max(expires - datetime.datetime.utcnow(),
284
286
                            datetime.timedelta())
285
 
            message = ('A checker has failed! Time until client'
286
 
                       ' gets disabled: {}'
 
287
            message = ("A checker has failed! Time until client"
 
288
                       " gets disabled: {}"
287
289
                       .format(str(timer).rsplit(".", 1)[0]))
288
290
            self.using_timer(True)
289
291
        else:
387
389
            self.update()
388
390
 
389
391
 
 
392
def glib_safely(func, retval=True):
 
393
    def safe_func(*args, **kwargs):
 
394
        try:
 
395
            return func(*args, **kwargs)
 
396
        except Exception:
 
397
            log.exception("")
 
398
            return retval
 
399
    return safe_func
 
400
 
 
401
 
390
402
class ConstrainedListBox(urwid.ListBox):
391
403
    """Like a normal urwid.ListBox, but will consume all "up" or
392
404
    "down" key presses, thus not allowing any containing widgets to
400
412
        return ret
401
413
 
402
414
 
403
 
class UserInterface(object):
 
415
class UserInterface:
404
416
    """This is the entire user interface - the whole screen
405
417
    with boxes, lists of client widgets, etc.
406
418
    """
407
 
    def __init__(self, max_log_length=1000, log_level=1):
 
419
    def __init__(self, max_log_length=1000):
408
420
        DBusGMainLoop(set_as_default=True)
409
421
 
410
422
        self.screen = urwid.curses_display.Screen()
447
459
        self.log = urwid.SimpleListWalker([])
448
460
        self.max_log_length = max_log_length
449
461
 
450
 
        self.log_level = log_level
451
 
 
452
462
        # We keep a reference to the log widget so we can remove it
453
463
        # from the ListWalker without it getting destroyed
454
464
        self.logbox = ConstrainedListBox(self.log)
458
468
        self.log_visible = True
459
469
        self.log_wrap = "any"
460
470
 
 
471
        self.loghandler = UILogHandler(self)
 
472
 
461
473
        self.rebuild()
462
 
        self.log_message_raw(("bold",
463
 
                              "Mandos Monitor version " + version))
464
 
        self.log_message_raw(("bold",
465
 
                              "q: Quit  ?: Help"))
 
474
        self.add_log_line(("bold",
 
475
                           "Mandos Monitor version " + version))
 
476
        self.add_log_line(("bold", "q: Quit  ?: Help"))
466
477
 
467
 
        self.busname = domain + '.Mandos'
 
478
        self.busname = domain + ".Mandos"
468
479
        self.main_loop = GLib.MainLoop()
469
480
 
470
 
    def client_not_found(self, fingerprint, address):
471
 
        self.log_message("Client with address {} and fingerprint {}"
472
 
                         " could not be found"
473
 
                         .format(address, fingerprint))
 
481
    def client_not_found(self, key_id, address):
 
482
        log.info("Client with address %s and key ID %s could"
 
483
                 " not be found", address, key_id)
474
484
 
475
485
    def rebuild(self):
476
486
        """This rebuilds the User Interface.
487
497
            self.uilist.append(self.logbox)
488
498
        self.topwidget = urwid.Pile(self.uilist)
489
499
 
490
 
    def log_message(self, message, level=1):
491
 
        """Log message formatted with timestamp"""
492
 
        if level < self.log_level:
493
 
            return
494
 
        timestamp = datetime.datetime.now().isoformat()
495
 
        self.log_message_raw("{}: {}".format(timestamp, message),
496
 
                             level=level)
497
 
 
498
 
    def log_message_raw(self, markup, level=1):
499
 
        """Add a log message to the log buffer."""
500
 
        if level < self.log_level:
501
 
            return
 
500
    def add_log_line(self, markup):
502
501
        self.log.append(urwid.Text(markup, wrap=self.log_wrap))
503
502
        if self.max_log_length:
504
503
            if len(self.log) > self.max_log_length:
505
 
                del self.log[0:len(self.log)-self.max_log_length-1]
 
504
                del self.log[0:(len(self.log) - self.max_log_length)]
506
505
        self.logbox.set_focus(len(self.logbox.body.contents)-1,
507
506
                              coming_from="above")
508
507
        self.refresh()
511
510
        """Toggle visibility of the log buffer."""
512
511
        self.log_visible = not self.log_visible
513
512
        self.rebuild()
514
 
        self.log_message("Log visibility changed to: {}"
515
 
                         .format(self.log_visible), level=0)
 
513
        log.debug("Log visibility changed to: %s", self.log_visible)
516
514
 
517
515
    def change_log_display(self):
518
516
        """Change type of log display.
523
521
            self.log_wrap = "clip"
524
522
        for textwidget in self.log:
525
523
            textwidget.set_wrap_mode(self.log_wrap)
526
 
        self.log_message("Wrap mode: {}".format(self.log_wrap),
527
 
                         level=0)
 
524
        log.debug("Wrap mode: %s", self.log_wrap)
528
525
 
529
526
    def find_and_remove_client(self, path, interfaces):
530
527
        """Find a client by its object path and remove it.
538
535
            client = self.clients_dict[path]
539
536
        except KeyError:
540
537
            # not found?
541
 
            self.log_message("Unknown client {!r} removed"
542
 
                             .format(path))
 
538
            log.warning("Unknown client %s removed", path)
543
539
            return
544
540
        client.delete()
545
541
 
558
554
            proxy_object=client_proxy_object,
559
555
            update_hook=self.refresh,
560
556
            delete_hook=self.remove_client,
561
 
            logger=self.log_message,
562
557
            properties=dict(ifs_and_props[client_interface])),
563
558
                        path=path)
564
559
 
584
579
 
585
580
    def run(self):
586
581
        """Start the main loop and exit when it's done."""
 
582
        log.addHandler(self.loghandler)
 
583
        self.orig_log_propagate = log.propagate
 
584
        log.propagate = False
 
585
        self.orig_log_level = log.level
 
586
        log.setLevel("INFO")
587
587
        self.bus = dbus.SystemBus()
588
588
        mandos_dbus_objc = self.bus.get_object(
589
589
            self.busname, "/", follow_name_owner_changes=True)
593
593
            mandos_clients = (self.mandos_serv
594
594
                              .GetAllClientsWithProperties())
595
595
            if not mandos_clients:
596
 
                self.log_message_raw(("bold",
597
 
                                      "Note: Server has no clients."))
 
596
                log.warning("Note: Server has no clients.")
598
597
        except dbus.exceptions.DBusException:
599
 
            self.log_message_raw(("bold",
600
 
                                  "Note: No Mandos server running."))
 
598
            log.warning("Note: No Mandos server running.")
601
599
            mandos_clients = dbus.Dictionary()
602
600
 
603
601
        (self.mandos_serv
623
621
                proxy_object=client_proxy_object,
624
622
                properties=client,
625
623
                update_hook=self.refresh,
626
 
                delete_hook=self.remove_client,
627
 
                logger=self.log_message),
 
624
                delete_hook=self.remove_client),
628
625
                            path=path)
629
626
 
630
627
        self.refresh()
631
 
        self._input_callback_tag = (GLib.io_add_watch
632
 
                                    (sys.stdin.fileno(),
633
 
                                     GLib.IO_IN,
634
 
                                     self.process_input))
 
628
        self._input_callback_tag = (
 
629
            GLib.io_add_watch(
 
630
                GLib.IOChannel.unix_new(sys.stdin.fileno()),
 
631
                GLib.PRIORITY_DEFAULT, GLib.IO_IN,
 
632
                glib_safely(self.process_input)))
635
633
        self.main_loop.run()
636
634
        # Main loop has finished, we should close everything now
637
635
        GLib.source_remove(self._input_callback_tag)
638
 
        self.screen.stop()
 
636
        with warnings.catch_warnings():
 
637
            warnings.simplefilter("ignore", BytesWarning)
 
638
            self.screen.stop()
639
639
 
640
640
    def stop(self):
641
641
        self.main_loop.quit()
 
642
        log.removeHandler(self.loghandler)
 
643
        log.propagate = self.orig_log_propagate
642
644
 
643
645
    def process_input(self, source, condition):
644
646
        keys = self.screen.get_input()
677
679
                if not self.log_visible:
678
680
                    self.log_visible = True
679
681
                    self.rebuild()
680
 
                self.log_message_raw(("bold",
681
 
                                      "  ".
682
 
                                      join(("q: Quit",
683
 
                                            "?: Help",
684
 
                                            "l: Log window toggle",
685
 
                                            "TAB: Switch window",
686
 
                                            "w: Wrap (log lines)",
687
 
                                            "v: Toggle verbose log",
688
 
                                            ))))
689
 
                self.log_message_raw(("bold",
690
 
                                      "  "
691
 
                                      .join(("Clients:",
692
 
                                             "+: Enable",
693
 
                                             "-: Disable",
694
 
                                             "R: Remove",
695
 
                                             "s: Start new checker",
696
 
                                             "S: Stop checker",
697
 
                                             "C: Checker OK",
698
 
                                             "a: Approve",
699
 
                                             "d: Deny"))))
 
682
                self.add_log_line(("bold",
 
683
                                   "  ".join(("q: Quit",
 
684
                                              "?: Help",
 
685
                                              "l: Log window toggle",
 
686
                                              "TAB: Switch window",
 
687
                                              "w: Wrap (log lines)",
 
688
                                              "v: Toggle verbose log",
 
689
                                   ))))
 
690
                self.add_log_line(("bold",
 
691
                                   "  ".join(("Clients:",
 
692
                                              "+: Enable",
 
693
                                              "-: Disable",
 
694
                                              "R: Remove",
 
695
                                              "s: Start new checker",
 
696
                                              "S: Stop checker",
 
697
                                              "C: Checker OK",
 
698
                                              "a: Approve",
 
699
                                              "d: Deny",
 
700
                                   ))))
700
701
                self.refresh()
701
702
            elif key == "tab":
702
703
                if self.topwidget.get_focus() is self.logbox:
705
706
                    self.topwidget.set_focus(self.logbox)
706
707
                self.refresh()
707
708
            elif key == "v":
708
 
                if self.log_level == 0:
709
 
                    self.log_level = 1
710
 
                    self.log_message("Verbose mode: Off")
 
709
                if log.level < logging.INFO:
 
710
                    log.setLevel(logging.INFO)
 
711
                    log.info("Verbose mode: Off")
711
712
                else:
712
 
                    self.log_level = 0
713
 
                    self.log_message("Verbose mode: On")
 
713
                    log.setLevel(logging.NOTSET)
 
714
                    log.info("Verbose mode: On")
714
715
            # elif (key == "end" or key == "meta >" or key == "G"
715
716
            #       or key == ">"):
716
717
            #     pass            # xxx end-of-buffer
735
736
        return True
736
737
 
737
738
 
 
739
class UILogHandler(logging.Handler):
 
740
    def __init__(self, ui, *args, **kwargs):
 
741
        self.ui = ui
 
742
        super(UILogHandler, self).__init__(*args, **kwargs)
 
743
        self.setFormatter(
 
744
            logging.Formatter("%(asctime)s: %(message)s"))
 
745
    def emit(self, record):
 
746
        msg = self.format(record)
 
747
        if record.levelno > logging.INFO:
 
748
            msg = ("bold", msg)
 
749
        self.ui.add_log_line(msg)
 
750
 
 
751
 
738
752
ui = UserInterface()
739
753
try:
740
754
    ui.run()
741
755
except KeyboardInterrupt:
742
 
    ui.screen.stop()
743
 
except Exception as e:
744
 
    ui.log_message(str(e))
745
 
    ui.screen.stop()
 
756
    with warnings.catch_warnings():
 
757
        warnings.filterwarnings("ignore", "", BytesWarning)
 
758
        ui.screen.stop()
 
759
except Exception:
 
760
    with warnings.catch_warnings():
 
761
        warnings.filterwarnings("ignore", "", BytesWarning)
 
762
        ui.screen.stop()
746
763
    raise