/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: 2015-05-23 20:18:34 UTC
  • mto: This revision was merged to the branch mainline in revision 756.
  • Revision ID: teddy@recompile.se-20150523201834-e89ex4ito93yni8x
mandos: Use multiprocessing module to run checkers.

For a long time, the Mandos server has occasionally logged the message
"ERROR: Child process vanished".  This was never a fatal error, but it
has been annoying and slightly worrying, since a definite cause was
not found.  One potential cause could be the "multiprocessing" and
"subprocess" modules conflicting w.r.t. SIGCHLD.  To avoid this,
change the running of checkers from using subprocess.Popen
asynchronously to instead first create a multiprocessing.Process()
(which is asynchronous) calling a function, and have that function
then call subprocess.call() (which is synchronous).  In this way, the
only thing using any asynchronous subprocesses is the multiprocessing
module.

This makes it necessary to change one small thing in the D-Bus API,
since the subprocesses.call() function does not expose the raw wait(2)
status value.

DBUS-API (CheckerCompleted): Change the second value provided by this
                             D-Bus signal from the raw wait(2) status
                             to the actual terminating signal number.
mandos (subprocess_call_pipe): New function to be called by
                               multiprocessing.Process (starting a
                               separate process).
(Client.last_checker signal): New attribute for signal which
                              terminated last checker.  Like
                              last_checker_status, only not accessible
                              via D-Bus.
(Client.checker_callback): Take new "connection" argument and use it
                           to get returncode; set last_checker_signal.
                           Return False so gobject does not call this
                           callback again.
(Client.start_checker): Start checker using a multiprocessing.Process
                        instead of a subprocess.Popen.
(ClientDBus.checker_callback): Take new "connection" argument.        Call
                               Client.checker_callback early to have
                               it set last_checker_status and
                               last_checker_signal; use those.  Change
                               second value provided to D-Bus signal
                               CheckerCompleted to use
                               last_checker_signal if checker was
                               terminated by signal.
mandos-monitor: Update to reflect DBus API change.
(MandosClientWidget.checker_completed): Take "signal" instead of
                                        "condition" argument.  Use it
                                        accordingly.  Remove dead code
                                        (os.WCOREDUMP case).

Show diffs side-by-side

added added

removed removed

Lines of Context:
3
3
4
4
# Mandos Monitor - Control and monitor the Mandos server
5
5
6
 
# Copyright © 2009-2012 Teddy Hogeborn
7
 
# Copyright © 2009-2012 Björn Påhlsson
 
6
# Copyright © 2009-2015 Teddy Hogeborn
 
7
# Copyright © 2009-2015 Björn Påhlsson
8
8
9
9
# This program is free software: you can redistribute it and/or modify
10
10
# it under the terms of the GNU General Public License as published by
25
25
 
26
26
from __future__ import (division, absolute_import, print_function,
27
27
                        unicode_literals)
28
 
 
29
 
from future_builtins import *
 
28
try:
 
29
    from future_builtins import *
 
30
except ImportError:
 
31
    pass
30
32
 
31
33
import sys
32
34
import os
33
 
import signal
34
35
 
35
36
import datetime
36
37
 
38
39
import urwid
39
40
 
40
41
from dbus.mainloop.glib import DBusGMainLoop
41
 
import gobject
 
42
try:
 
43
    import gobject
 
44
except ImportError:
 
45
    from gi.repository import GObject as gobject
42
46
 
43
47
import dbus
44
48
 
45
 
import UserList
46
 
 
47
49
import locale
48
50
 
 
51
if sys.version_info.major == 2:
 
52
    str = unicode
 
53
 
49
54
locale.setlocale(locale.LC_ALL, '')
50
55
 
51
56
import logging
55
60
domain = 'se.recompile'
56
61
server_interface = domain + '.Mandos'
57
62
client_interface = domain + '.Mandos.Client'
58
 
version = "1.5.4"
59
 
 
60
 
# Always run in monochrome mode
61
 
urwid.curses_display.curses.has_colors = lambda : False
62
 
 
63
 
# Urwid doesn't support blinking, but we want it.  Since we have no
64
 
# use for underline on its own, we make underline also always blink.
65
 
urwid.curses_display.curses.A_UNDERLINE |= (
66
 
    urwid.curses_display.curses.A_BLINK)
 
63
version = "1.6.9"
67
64
 
68
65
def isoformat_to_datetime(iso):
69
66
    "Parse an ISO 8601 date string to a datetime.datetime()"
90
87
        self.proxy = proxy_object # Mandos Client proxy object
91
88
        self.properties = dict() if properties is None else properties
92
89
        self.property_changed_match = (
93
 
            self.proxy.connect_to_signal("PropertyChanged",
94
 
                                         self._property_changed,
95
 
                                         client_interface,
 
90
            self.proxy.connect_to_signal("PropertiesChanged",
 
91
                                         self.properties_changed,
 
92
                                         dbus.PROPERTIES_IFACE,
96
93
                                         byte_arrays=True))
97
94
        
98
95
        if properties is None:
103
100
        
104
101
        super(MandosClientPropertyCache, self).__init__(**kwargs)
105
102
    
106
 
    def _property_changed(self, property, value):
107
 
        """Helper which takes positional arguments"""
108
 
        return self.property_changed(property=property, value=value)
109
 
    
110
 
    def property_changed(self, property=None, value=None):
111
 
        """This is called whenever we get a PropertyChanged signal
112
 
        It updates the changed property in the "properties" dict.
 
103
    def properties_changed(self, interface, properties, invalidated):
 
104
        """This is called whenever we get a PropertiesChanged signal
 
105
        It updates the changed properties in the "properties" dict.
113
106
        """
114
107
        # Update properties dict with new value
115
 
        self.properties[property] = value
 
108
        self.properties.update(properties)
116
109
    
117
110
    def delete(self):
118
111
        self.property_changed_match.remove()
164
157
                                         self.rejected,
165
158
                                         client_interface,
166
159
                                         byte_arrays=True))
167
 
        #self.logger('Created client {0}'
168
 
        #            .format(self.properties["Name"]))
 
160
        self.logger('Created client {}'
 
161
                    .format(self.properties["Name"]), level=0)
169
162
    
170
163
    def using_timer(self, flag):
171
164
        """Call this method with True or False when timer should be
180
173
            gobject.source_remove(self._update_timer_callback_tag)
181
174
            self._update_timer_callback_tag = None
182
175
    
183
 
    def checker_completed(self, exitstatus, condition, command):
 
176
    def checker_completed(self, exitstatus, signal, command):
184
177
        if exitstatus == 0:
 
178
            self.logger('Checker for client {} (command "{}")'
 
179
                        ' succeeded'.format(self.properties["Name"],
 
180
                                            command), level=0)
185
181
            self.update()
186
182
            return
187
183
        # Checker failed
188
 
        if os.WIFEXITED(condition):
189
 
            self.logger('Checker for client {0} (command "{1}")'
190
 
                        ' failed with exit code {2}'
191
 
                        .format(self.properties["Name"], command,
192
 
                                os.WEXITSTATUS(condition)))
193
 
        elif os.WIFSIGNALED(condition):
194
 
            self.logger('Checker for client {0} (command "{1}") was'
195
 
                        ' killed by signal {2}'
196
 
                        .format(self.properties["Name"], command,
197
 
                                os.WTERMSIG(condition)))
198
 
        elif os.WCOREDUMP(condition):
199
 
            self.logger('Checker for client {0} (command "{1}")'
200
 
                        ' dumped core'
201
 
                        .format(self.properties["Name"], command))
 
184
        if exitstatus >= 0:
 
185
            self.logger('Checker for client {} (command "{}") failed'
 
186
                        ' with exit code {}'
 
187
                        .format(self.properties["Name"], command,
 
188
                                exitstatus))
 
189
        elif signal != 0:
 
190
            self.logger('Checker for client {} (command "{}") was'
 
191
                        ' killed by signal {}'
 
192
                        .format(self.properties["Name"], command,
 
193
                                signal))
202
194
        else:
203
 
            self.logger('Checker for client {0} completed'
 
195
            self.logger('Checker for client {} completed'
204
196
                        ' mysteriously'
205
197
                        .format(self.properties["Name"]))
206
198
        self.update()
207
199
    
208
200
    def checker_started(self, command):
209
 
        """Server signals that a checker started. This could be useful
210
 
           to log in the future. """
211
 
        #self.logger('Client {0} started checker "{1}"'
212
 
        #            .format(self.properties["Name"],
213
 
        #                    unicode(command)))
214
 
        pass
 
201
        """Server signals that a checker started."""
 
202
        self.logger('Client {} started checker "{}"'
 
203
                    .format(self.properties["Name"],
 
204
                            command), level=0)
215
205
    
216
206
    def got_secret(self):
217
 
        self.logger('Client {0} received its secret'
 
207
        self.logger('Client {} received its secret'
218
208
                    .format(self.properties["Name"]))
219
209
    
220
210
    def need_approval(self, timeout, default):
221
211
        if not default:
222
 
            message = 'Client {0} needs approval within {1} seconds'
 
212
            message = 'Client {} needs approval within {} seconds'
223
213
        else:
224
 
            message = 'Client {0} will get its secret in {1} seconds'
 
214
            message = 'Client {} will get its secret in {} seconds'
225
215
        self.logger(message.format(self.properties["Name"],
226
216
                                   timeout/1000))
227
217
    
228
218
    def rejected(self, reason):
229
 
        self.logger('Client {0} was rejected; reason: {1}'
 
219
        self.logger('Client {} was rejected; reason: {}'
230
220
                    .format(self.properties["Name"], reason))
231
221
    
232
222
    def selectable(self):
276
266
            else:
277
267
                timer = datetime.timedelta()
278
268
            if self.properties["ApprovedByDefault"]:
279
 
                message = "Approval in {0}. (d)eny?"
 
269
                message = "Approval in {}. (d)eny?"
280
270
            else:
281
 
                message = "Denial in {0}. (a)pprove?"
282
 
            message = message.format(unicode(timer).rsplit(".", 1)[0])
 
271
                message = "Denial in {}. (a)pprove?"
 
272
            message = message.format(str(timer).rsplit(".", 1)[0])
283
273
            self.using_timer(True)
284
274
        elif self.properties["LastCheckerStatus"] != 0:
285
275
            # When checker has failed, show timer until client expires
292
282
                timer = max(expires - datetime.datetime.utcnow(),
293
283
                            datetime.timedelta())
294
284
            message = ('A checker has failed! Time until client'
295
 
                       ' gets disabled: {0}'
296
 
                       .format(unicode(timer).rsplit(".", 1)[0]))
 
285
                       ' gets disabled: {}'
 
286
                       .format(str(timer).rsplit(".", 1)[0]))
297
287
            self.using_timer(True)
298
288
        else:
299
289
            message = "enabled"
300
290
            self.using_timer(False)
301
 
        self._text = "{0}{1}".format(base, message)
 
291
        self._text = "{}{}".format(base, message)
302
292
        
303
293
        if not urwid.supports_unicode():
304
294
            self._text = self._text.encode("ascii", "replace")
379
369
        else:
380
370
            return key
381
371
    
382
 
    def property_changed(self, property=None, **kwargs):
383
 
        """Call self.update() if old value is not new value.
 
372
    def properties_changed(self, interface, properties, invalidated):
 
373
        """Call self.update() if any properties changed.
384
374
        This overrides the method from MandosClientPropertyCache"""
385
 
        property_name = unicode(property)
386
 
        old_value = self.properties.get(property_name)
387
 
        super(MandosClientWidget, self).property_changed(
388
 
            property=property, **kwargs)
389
 
        if self.properties.get(property_name) != old_value:
 
375
        old_values = { key: self.properties.get(key)
 
376
                       for key in properties.keys() }
 
377
        super(MandosClientWidget, self).properties_changed(
 
378
            interface, properties, invalidated)
 
379
        if any(old_values[key] != self.properties.get(key)
 
380
               for key in old_values):
390
381
            self.update()
391
382
 
392
383
 
406
397
    """This is the entire user interface - the whole screen
407
398
    with boxes, lists of client widgets, etc.
408
399
    """
409
 
    def __init__(self, max_log_length=1000):
 
400
    def __init__(self, max_log_length=1000, log_level=1):
410
401
        DBusGMainLoop(set_as_default=True)
411
402
        
412
403
        self.screen = urwid.curses_display.Screen()
415
406
                ("normal",
416
407
                 "default", "default", None),
417
408
                ("bold",
418
 
                 "default", "default", "bold"),
 
409
                 "bold", "default", "bold"),
419
410
                ("underline-blink",
420
 
                 "default", "default", "underline"),
 
411
                 "underline,blink", "default", "underline,blink"),
421
412
                ("standout",
422
 
                 "default", "default", "standout"),
 
413
                 "standout", "default", "standout"),
423
414
                ("bold-underline-blink",
424
 
                 "default", "default", ("bold", "underline")),
 
415
                 "bold,underline,blink", "default", "bold,underline,blink"),
425
416
                ("bold-standout",
426
 
                 "default", "default", ("bold", "standout")),
 
417
                 "bold,standout", "default", "bold,standout"),
427
418
                ("underline-blink-standout",
428
 
                 "default", "default", ("underline", "standout")),
 
419
                 "underline,blink,standout", "default",
 
420
                 "underline,blink,standout"),
429
421
                ("bold-underline-blink-standout",
430
 
                 "default", "default", ("bold", "underline",
431
 
                                          "standout")),
 
422
                 "bold,underline,blink,standout", "default",
 
423
                 "bold,underline,blink,standout"),
432
424
                ))
433
425
        
434
426
        if urwid.supports_unicode():
449
441
        self.log = []
450
442
        self.max_log_length = max_log_length
451
443
        
 
444
        self.log_level = log_level
 
445
        
452
446
        # We keep a reference to the log widget so we can remove it
453
447
        # from the ListWalker without it getting destroyed
454
448
        self.logbox = ConstrainedListBox(self.log)
468
462
        self.main_loop = gobject.MainLoop()
469
463
    
470
464
    def client_not_found(self, fingerprint, address):
471
 
        self.log_message("Client with address {0} and fingerprint"
472
 
                         " {1} could not be found"
 
465
        self.log_message("Client with address {} and fingerprint {}"
 
466
                         " could not be found"
473
467
                         .format(address, fingerprint))
474
468
    
475
469
    def rebuild(self):
488
482
            self.uilist.append(self.logbox)
489
483
        self.topwidget = urwid.Pile(self.uilist)
490
484
    
491
 
    def log_message(self, message):
 
485
    def log_message(self, message, level=1):
 
486
        """Log message formatted with timestamp"""
 
487
        if level < self.log_level:
 
488
            return
492
489
        timestamp = datetime.datetime.now().isoformat()
493
 
        self.log_message_raw(timestamp + ": " + message)
 
490
        self.log_message_raw("{}: {}".format(timestamp, message),
 
491
                             level=level)
494
492
    
495
 
    def log_message_raw(self, markup):
 
493
    def log_message_raw(self, markup, level=1):
496
494
        """Add a log message to the log buffer."""
 
495
        if level < self.log_level:
 
496
            return
497
497
        self.log.append(urwid.Text(markup, wrap=self.log_wrap))
498
498
        if (self.max_log_length
499
499
            and len(self.log) > self.max_log_length):
506
506
        """Toggle visibility of the log buffer."""
507
507
        self.log_visible = not self.log_visible
508
508
        self.rebuild()
509
 
        #self.log_message("Log visibility changed to: "
510
 
        #                 + unicode(self.log_visible))
 
509
        self.log_message("Log visibility changed to: {}"
 
510
                         .format(self.log_visible), level=0)
511
511
    
512
512
    def change_log_display(self):
513
513
        """Change type of log display.
518
518
            self.log_wrap = "clip"
519
519
        for textwidget in self.log:
520
520
            textwidget.set_wrap_mode(self.log_wrap)
521
 
        #self.log_message("Wrap mode: " + self.log_wrap)
 
521
        self.log_message("Wrap mode: {}".format(self.log_wrap),
 
522
                         level=0)
522
523
    
523
524
    def find_and_remove_client(self, path, name):
524
525
        """Find a client by its object path and remove it.
529
530
            client = self.clients_dict[path]
530
531
        except KeyError:
531
532
            # not found?
532
 
            self.log_message("Unknown client {0!r} ({1!r}) removed"
 
533
            self.log_message("Unknown client {!r} ({!r}) removed"
533
534
                             .format(name, path))
534
535
            return
535
536
        client.delete()
553
554
        if path is None:
554
555
            path = client.proxy.object_path
555
556
        self.clients_dict[path] = client
556
 
        self.clients.sort(None, lambda c: c.properties["Name"])
 
557
        self.clients.sort(key=lambda c: c.properties["Name"])
557
558
        self.refresh()
558
559
    
559
560
    def remove_client(self, client, path=None):
561
562
        if path is None:
562
563
            path = client.proxy.object_path
563
564
        del self.clients_dict[path]
564
 
        if not self.clients_dict:
565
 
            # Work around bug in Urwid 0.9.8.3 - if a SimpleListWalker
566
 
            # is completely emptied, we need to recreate it.
567
 
            self.clients = urwid.SimpleListWalker([])
568
 
            self.rebuild()
569
565
        self.refresh()
570
566
    
571
567
    def refresh(self):
584
580
        try:
585
581
            mandos_clients = (self.mandos_serv
586
582
                              .GetAllClientsWithProperties())
 
583
            if not mandos_clients:
 
584
                self.log_message_raw(("bold", "Note: Server has no clients."))
587
585
        except dbus.exceptions.DBusException:
 
586
            self.log_message_raw(("bold", "Note: No Mandos server running."))
588
587
            mandos_clients = dbus.Dictionary()
589
588
        
590
589
        (self.mandos_serv
602
601
                            self.client_not_found,
603
602
                            dbus_interface=server_interface,
604
603
                            byte_arrays=True))
605
 
        for path, client in mandos_clients.iteritems():
 
604
        for path, client in mandos_clients.items():
606
605
            client_proxy_object = self.bus.get_object(self.busname,
607
606
                                                      path)
608
607
            self.add_client(MandosClientWidget(server_proxy_object
655
654
            elif key == "window resize":
656
655
                self.size = self.screen.get_cols_rows()
657
656
                self.refresh()
658
 
            elif key == "\f":  # Ctrl-L
 
657
            elif key == "ctrl l":
 
658
                self.screen.clear()
659
659
                self.refresh()
660
660
            elif key == "l" or key == "D":
661
661
                self.toggle_log_display()
673
673
                                            "?: Help",
674
674
                                            "l: Log window toggle",
675
675
                                            "TAB: Switch window",
676
 
                                            "w: Wrap (log)"))))
 
676
                                            "w: Wrap (log lines)",
 
677
                                            "v: Toggle verbose log",
 
678
                                            ))))
677
679
                self.log_message_raw(("bold",
678
680
                                      "  "
679
681
                                      .join(("Clients:",
692
694
                else:
693
695
                    self.topwidget.set_focus(self.logbox)
694
696
                self.refresh()
 
697
            elif key == "v":
 
698
                if self.log_level == 0:
 
699
                    self.log_level = 1
 
700
                    self.log_message("Verbose mode: Off")
 
701
                else:
 
702
                    self.log_level = 0
 
703
                    self.log_message("Verbose mode: On")
695
704
            #elif (key == "end" or key == "meta >" or key == "G"
696
705
            #      or key == ">"):
697
706
            #    pass            # xxx end-of-buffer
720
729
    ui.run()
721
730
except KeyboardInterrupt:
722
731
    ui.screen.stop()
723
 
except Exception, e:
724
 
    ui.log_message(unicode(e))
 
732
except Exception as e:
 
733
    ui.log_message(str(e))
725
734
    ui.screen.stop()
726
735
    raise