/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: 2024-11-22 20:28:54 UTC
  • Revision ID: teddy@recompile.se-20241122202854-dycuf117byxhxl32
mandos-monitor: Avoid debug messages from urwid

Avoid debug messages from urwid.  Any logging output before the screen
has been set up will mangle the screen.

* mandos-monitor: When setting up logging, set urwid to only show log
  messages of level INFO or above.

(Thanks to an anonymous contributor for reporting this.)

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