/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-2014 Teddy Hogeborn
7
 
# Copyright © 2009-2014 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
48
48
 
49
49
import locale
50
50
 
51
 
if sys.version_info[0] == 2:
 
51
if sys.version_info.major == 2:
52
52
    str = unicode
53
53
 
54
54
locale.setlocale(locale.LC_ALL, '')
60
60
domain = 'se.recompile'
61
61
server_interface = domain + '.Mandos'
62
62
client_interface = domain + '.Mandos.Client'
63
 
version = "1.6.4"
 
63
version = "1.6.9"
64
64
 
65
65
def isoformat_to_datetime(iso):
66
66
    "Parse an ISO 8601 date string to a datetime.datetime()"
87
87
        self.proxy = proxy_object # Mandos Client proxy object
88
88
        self.properties = dict() if properties is None else properties
89
89
        self.property_changed_match = (
90
 
            self.proxy.connect_to_signal("PropertyChanged",
91
 
                                         self._property_changed,
92
 
                                         client_interface,
 
90
            self.proxy.connect_to_signal("PropertiesChanged",
 
91
                                         self.properties_changed,
 
92
                                         dbus.PROPERTIES_IFACE,
93
93
                                         byte_arrays=True))
94
94
        
95
95
        if properties is None:
100
100
        
101
101
        super(MandosClientPropertyCache, self).__init__(**kwargs)
102
102
    
103
 
    def _property_changed(self, property, value):
104
 
        """Helper which takes positional arguments"""
105
 
        return self.property_changed(property=property, value=value)
106
 
    
107
 
    def property_changed(self, property=None, value=None):
108
 
        """This is called whenever we get a PropertyChanged signal
109
 
        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.
110
106
        """
111
107
        # Update properties dict with new value
112
 
        self.properties[property] = value
 
108
        self.properties.update(properties)
113
109
    
114
110
    def delete(self):
115
111
        self.property_changed_match.remove()
161
157
                                         self.rejected,
162
158
                                         client_interface,
163
159
                                         byte_arrays=True))
164
 
        #self.logger('Created client {0}'
165
 
        #            .format(self.properties["Name"]))
 
160
        self.logger('Created client {}'
 
161
                    .format(self.properties["Name"]), level=0)
166
162
    
167
163
    def using_timer(self, flag):
168
164
        """Call this method with True or False when timer should be
177
173
            gobject.source_remove(self._update_timer_callback_tag)
178
174
            self._update_timer_callback_tag = None
179
175
    
180
 
    def checker_completed(self, exitstatus, condition, command):
 
176
    def checker_completed(self, exitstatus, signal, command):
181
177
        if exitstatus == 0:
 
178
            self.logger('Checker for client {} (command "{}")'
 
179
                        ' succeeded'.format(self.properties["Name"],
 
180
                                            command), level=0)
182
181
            self.update()
183
182
            return
184
183
        # Checker failed
185
 
        if os.WIFEXITED(condition):
186
 
            self.logger('Checker for client {0} (command "{1}")'
187
 
                        ' failed with exit code {2}'
188
 
                        .format(self.properties["Name"], command,
189
 
                                os.WEXITSTATUS(condition)))
190
 
        elif os.WIFSIGNALED(condition):
191
 
            self.logger('Checker for client {0} (command "{1}") was'
192
 
                        ' killed by signal {2}'
193
 
                        .format(self.properties["Name"], command,
194
 
                                os.WTERMSIG(condition)))
195
 
        elif os.WCOREDUMP(condition):
196
 
            self.logger('Checker for client {0} (command "{1}")'
197
 
                        ' dumped core'
198
 
                        .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))
199
194
        else:
200
 
            self.logger('Checker for client {0} completed'
 
195
            self.logger('Checker for client {} completed'
201
196
                        ' mysteriously'
202
197
                        .format(self.properties["Name"]))
203
198
        self.update()
204
199
    
205
200
    def checker_started(self, command):
206
 
        """Server signals that a checker started. This could be useful
207
 
           to log in the future. """
208
 
        #self.logger('Client {0} started checker "{1}"'
209
 
        #            .format(self.properties["Name"],
210
 
        #                    str(command)))
211
 
        pass
 
201
        """Server signals that a checker started."""
 
202
        self.logger('Client {} started checker "{}"'
 
203
                    .format(self.properties["Name"],
 
204
                            command), level=0)
212
205
    
213
206
    def got_secret(self):
214
 
        self.logger('Client {0} received its secret'
 
207
        self.logger('Client {} received its secret'
215
208
                    .format(self.properties["Name"]))
216
209
    
217
210
    def need_approval(self, timeout, default):
218
211
        if not default:
219
 
            message = 'Client {0} needs approval within {1} seconds'
 
212
            message = 'Client {} needs approval within {} seconds'
220
213
        else:
221
 
            message = 'Client {0} will get its secret in {1} seconds'
 
214
            message = 'Client {} will get its secret in {} seconds'
222
215
        self.logger(message.format(self.properties["Name"],
223
216
                                   timeout/1000))
224
217
    
225
218
    def rejected(self, reason):
226
 
        self.logger('Client {0} was rejected; reason: {1}'
 
219
        self.logger('Client {} was rejected; reason: {}'
227
220
                    .format(self.properties["Name"], reason))
228
221
    
229
222
    def selectable(self):
273
266
            else:
274
267
                timer = datetime.timedelta()
275
268
            if self.properties["ApprovedByDefault"]:
276
 
                message = "Approval in {0}. (d)eny?"
 
269
                message = "Approval in {}. (d)eny?"
277
270
            else:
278
 
                message = "Denial in {0}. (a)pprove?"
 
271
                message = "Denial in {}. (a)pprove?"
279
272
            message = message.format(str(timer).rsplit(".", 1)[0])
280
273
            self.using_timer(True)
281
274
        elif self.properties["LastCheckerStatus"] != 0:
289
282
                timer = max(expires - datetime.datetime.utcnow(),
290
283
                            datetime.timedelta())
291
284
            message = ('A checker has failed! Time until client'
292
 
                       ' gets disabled: {0}'
 
285
                       ' gets disabled: {}'
293
286
                       .format(str(timer).rsplit(".", 1)[0]))
294
287
            self.using_timer(True)
295
288
        else:
296
289
            message = "enabled"
297
290
            self.using_timer(False)
298
 
        self._text = "{0}{1}".format(base, message)
 
291
        self._text = "{}{}".format(base, message)
299
292
        
300
293
        if not urwid.supports_unicode():
301
294
            self._text = self._text.encode("ascii", "replace")
376
369
        else:
377
370
            return key
378
371
    
379
 
    def property_changed(self, property=None, **kwargs):
380
 
        """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.
381
374
        This overrides the method from MandosClientPropertyCache"""
382
 
        property_name = str(property)
383
 
        old_value = self.properties.get(property_name)
384
 
        super(MandosClientWidget, self).property_changed(
385
 
            property=property, **kwargs)
386
 
        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):
387
381
            self.update()
388
382
 
389
383
 
403
397
    """This is the entire user interface - the whole screen
404
398
    with boxes, lists of client widgets, etc.
405
399
    """
406
 
    def __init__(self, max_log_length=1000):
 
400
    def __init__(self, max_log_length=1000, log_level=1):
407
401
        DBusGMainLoop(set_as_default=True)
408
402
        
409
403
        self.screen = urwid.curses_display.Screen()
447
441
        self.log = []
448
442
        self.max_log_length = max_log_length
449
443
        
 
444
        self.log_level = log_level
 
445
        
450
446
        # We keep a reference to the log widget so we can remove it
451
447
        # from the ListWalker without it getting destroyed
452
448
        self.logbox = ConstrainedListBox(self.log)
466
462
        self.main_loop = gobject.MainLoop()
467
463
    
468
464
    def client_not_found(self, fingerprint, address):
469
 
        self.log_message("Client with address {0} and fingerprint"
470
 
                         " {1} could not be found"
 
465
        self.log_message("Client with address {} and fingerprint {}"
 
466
                         " could not be found"
471
467
                         .format(address, fingerprint))
472
468
    
473
469
    def rebuild(self):
486
482
            self.uilist.append(self.logbox)
487
483
        self.topwidget = urwid.Pile(self.uilist)
488
484
    
489
 
    def log_message(self, message):
 
485
    def log_message(self, message, level=1):
490
486
        """Log message formatted with timestamp"""
 
487
        if level < self.log_level:
 
488
            return
491
489
        timestamp = datetime.datetime.now().isoformat()
492
 
        self.log_message_raw(timestamp + ": " + message)
 
490
        self.log_message_raw("{}: {}".format(timestamp, message),
 
491
                             level=level)
493
492
    
494
 
    def log_message_raw(self, markup):
 
493
    def log_message_raw(self, markup, level=1):
495
494
        """Add a log message to the log buffer."""
 
495
        if level < self.log_level:
 
496
            return
496
497
        self.log.append(urwid.Text(markup, wrap=self.log_wrap))
497
498
        if (self.max_log_length
498
499
            and len(self.log) > self.max_log_length):
505
506
        """Toggle visibility of the log buffer."""
506
507
        self.log_visible = not self.log_visible
507
508
        self.rebuild()
508
 
        #self.log_message("Log visibility changed to: "
509
 
        #                 + str(self.log_visible))
 
509
        self.log_message("Log visibility changed to: {}"
 
510
                         .format(self.log_visible), level=0)
510
511
    
511
512
    def change_log_display(self):
512
513
        """Change type of log display.
517
518
            self.log_wrap = "clip"
518
519
        for textwidget in self.log:
519
520
            textwidget.set_wrap_mode(self.log_wrap)
520
 
        #self.log_message("Wrap mode: " + self.log_wrap)
 
521
        self.log_message("Wrap mode: {}".format(self.log_wrap),
 
522
                         level=0)
521
523
    
522
524
    def find_and_remove_client(self, path, name):
523
525
        """Find a client by its object path and remove it.
528
530
            client = self.clients_dict[path]
529
531
        except KeyError:
530
532
            # not found?
531
 
            self.log_message("Unknown client {0!r} ({1!r}) removed"
 
533
            self.log_message("Unknown client {!r} ({!r}) removed"
532
534
                             .format(name, path))
533
535
            return
534
536
        client.delete()
652
654
            elif key == "window resize":
653
655
                self.size = self.screen.get_cols_rows()
654
656
                self.refresh()
655
 
            elif key == "\f":  # Ctrl-L
 
657
            elif key == "ctrl l":
 
658
                self.screen.clear()
656
659
                self.refresh()
657
660
            elif key == "l" or key == "D":
658
661
                self.toggle_log_display()
670
673
                                            "?: Help",
671
674
                                            "l: Log window toggle",
672
675
                                            "TAB: Switch window",
673
 
                                            "w: Wrap (log)"))))
 
676
                                            "w: Wrap (log lines)",
 
677
                                            "v: Toggle verbose log",
 
678
                                            ))))
674
679
                self.log_message_raw(("bold",
675
680
                                      "  "
676
681
                                      .join(("Clients:",
689
694
                else:
690
695
                    self.topwidget.set_focus(self.logbox)
691
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")
692
704
            #elif (key == "end" or key == "meta >" or key == "G"
693
705
            #      or key == ">"):
694
706
            #    pass            # xxx end-of-buffer