/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

  • Committer: Teddy Hogeborn
  • Date: 2022-04-25 18:33:20 UTC
  • mfrom: (1260 trunk)
  • mto: This revision was merged to the branch mainline in revision 1261.
  • Revision ID: teddy@recompile.se-20220425183320-w83scg055sinkow4
Merge from trunk

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
1
#!/usr/bin/python3 -bI
2
 
# -*- mode: python; after-save-hook: (lambda () (let ((command (if (fboundp 'file-local-name) (file-local-name (buffer-file-name)) (or (file-remote-p (buffer-file-name) 'localname) (buffer-file-name))))) (if (= (progn (if (get-buffer "*Test*") (kill-buffer "*Test*")) (process-file-shell-command (format "%s --check" (shell-quote-argument command)) nil "*Test*")) 0) (let ((w (get-buffer-window "*Test*"))) (if w (delete-window w))) (progn (with-current-buffer "*Test*" (compilation-mode)) (display-buffer "*Test*" '(display-buffer-in-side-window)))))); coding: utf-8 -*-
 
2
# -*- coding: utf-8; lexical-binding: t -*-
3
3
#
4
4
# Mandos server - give out binary blobs to connecting clients.
5
5
#
11
11
# "AvahiService" class, and some lines in "main".
12
12
#
13
13
# Everything else is
14
 
# Copyright © 2008-2020 Teddy Hogeborn
15
 
# Copyright © 2008-2020 Björn Påhlsson
 
14
# Copyright © 2008-2022 Teddy Hogeborn
 
15
# Copyright © 2008-2022 Björn Påhlsson
16
16
#
17
17
# This file is part of Mandos.
18
18
#
31
31
#
32
32
# Contact the authors at <mandos@recompile.se>.
33
33
#
34
 
 
35
34
from __future__ import (division, absolute_import, print_function,
36
35
                        unicode_literals)
37
36
 
40
39
except ImportError:
41
40
    pass
42
41
 
 
42
import sys
 
43
import unittest
 
44
import argparse
 
45
import logging
 
46
import os
43
47
try:
44
48
    import SocketServer as socketserver
45
49
except ImportError:
46
50
    import socketserver
47
51
import socket
48
 
import argparse
49
52
import datetime
50
53
import errno
51
54
try:
52
55
    import ConfigParser as configparser
53
56
except ImportError:
54
57
    import configparser
55
 
import sys
56
58
import re
57
 
import os
58
59
import signal
59
60
import subprocess
60
61
import atexit
61
62
import stat
62
 
import logging
63
63
import logging.handlers
64
64
import pwd
65
65
import contextlib
77
77
import itertools
78
78
import collections
79
79
import codecs
80
 
import unittest
81
80
import random
82
81
import shlex
83
82
 
94
93
if sys.version_info.major == 2:
95
94
    __metaclass__ = type
96
95
    str = unicode
 
96
    input = raw_input
97
97
 
98
98
# Add collections.abc.Callable if it does not exist
99
99
try:
146
146
version = "1.8.14"
147
147
stored_state_file = "clients.pickle"
148
148
 
149
 
logger = logging.getLogger()
 
149
log = logging.getLogger(os.path.basename(sys.argv[0]))
150
150
logging.captureWarnings(True)   # Show warnings via the logging system
151
151
syslogger = None
152
152
 
189
189
        facility=logging.handlers.SysLogHandler.LOG_DAEMON,
190
190
        address="/dev/log"))
191
191
    syslogger.setFormatter(logging.Formatter
192
 
                           ('Mandos [%(process)d]: %(levelname)s:'
193
 
                            ' %(message)s'))
194
 
    logger.addHandler(syslogger)
 
192
                           ("Mandos [%(process)d]: %(levelname)s:"
 
193
                            " %(message)s"))
 
194
    log.addHandler(syslogger)
195
195
 
196
196
    if debug:
197
197
        console = logging.StreamHandler()
198
 
        console.setFormatter(logging.Formatter('%(asctime)s %(name)s'
199
 
                                               ' [%(process)d]:'
200
 
                                               ' %(levelname)s:'
201
 
                                               ' %(message)s'))
202
 
        logger.addHandler(console)
203
 
    logger.setLevel(level)
 
198
        console.setFormatter(logging.Formatter("%(asctime)s %(name)s"
 
199
                                               " [%(process)d]:"
 
200
                                               " %(levelname)s:"
 
201
                                               " %(message)s"))
 
202
        log.addHandler(console)
 
203
    log.setLevel(level)
204
204
 
205
205
 
206
206
class PGPError(Exception):
224
224
        except OSError as e:
225
225
            if e.errno != errno.ENOENT:
226
226
                raise
227
 
        self.gnupgargs = ['--batch',
228
 
                          '--homedir', self.tempdir,
229
 
                          '--force-mdc',
230
 
                          '--quiet']
 
227
        self.gnupgargs = ["--batch",
 
228
                          "--homedir", self.tempdir,
 
229
                          "--force-mdc",
 
230
                          "--quiet"]
231
231
        # Only GPG version 1 has the --no-use-agent option.
232
232
        if self.gpg == b"gpg" or self.gpg.endswith(b"/gpg"):
233
233
            self.gnupgargs.append("--no-use-agent")
272
272
                dir=self.tempdir) as passfile:
273
273
            passfile.write(passphrase)
274
274
            passfile.flush()
275
 
            proc = subprocess.Popen([self.gpg, '--symmetric',
276
 
                                     '--passphrase-file',
 
275
            proc = subprocess.Popen([self.gpg, "--symmetric",
 
276
                                     "--passphrase-file",
277
277
                                     passfile.name]
278
278
                                    + self.gnupgargs,
279
279
                                    stdin=subprocess.PIPE,
290
290
                dir=self.tempdir) as passfile:
291
291
            passfile.write(passphrase)
292
292
            passfile.flush()
293
 
            proc = subprocess.Popen([self.gpg, '--decrypt',
294
 
                                     '--passphrase-file',
 
293
            proc = subprocess.Popen([self.gpg, "--decrypt",
 
294
                                     "--passphrase-file",
295
295
                                     passfile.name]
296
296
                                    + self.gnupgargs,
297
297
                                    stdin=subprocess.PIPE,
350
350
    Attributes:
351
351
    interface: integer; avahi.IF_UNSPEC or an interface index.
352
352
               Used to optionally bind to the specified interface.
353
 
    name: string; Example: 'Mandos'
354
 
    type: string; Example: '_mandos._tcp'.
 
353
    name: string; Example: "Mandos"
 
354
    type: string; Example: "_mandos._tcp".
355
355
     See <https://www.iana.org/assignments/service-names-port-numbers>
356
356
    port: integer; what port to announce
357
357
    TXT: list of strings; TXT record for the service
394
394
    def rename(self, remove=True):
395
395
        """Derived from the Avahi example code"""
396
396
        if self.rename_count >= self.max_renames:
397
 
            logger.critical("No suitable Zeroconf service name found"
398
 
                            " after %i retries, exiting.",
399
 
                            self.rename_count)
 
397
            log.critical("No suitable Zeroconf service name found"
 
398
                         " after %i retries, exiting.",
 
399
                         self.rename_count)
400
400
            raise AvahiServiceError("Too many renames")
401
401
        self.name = str(
402
402
            self.server.GetAlternativeServiceName(self.name))
403
403
        self.rename_count += 1
404
 
        logger.info("Changing Zeroconf service name to %r ...",
405
 
                    self.name)
 
404
        log.info("Changing Zeroconf service name to %r ...",
 
405
                 self.name)
406
406
        if remove:
407
407
            self.remove()
408
408
        try:
410
410
        except dbus.exceptions.DBusException as error:
411
411
            if (error.get_dbus_name()
412
412
                == "org.freedesktop.Avahi.CollisionError"):
413
 
                logger.info("Local Zeroconf service name collision.")
 
413
                log.info("Local Zeroconf service name collision.")
414
414
                return self.rename(remove=False)
415
415
            else:
416
 
                logger.critical("D-Bus Exception", exc_info=error)
 
416
                log.critical("D-Bus Exception", exc_info=error)
417
417
                self.cleanup()
418
418
                os._exit(1)
419
419
 
435
435
                avahi.DBUS_INTERFACE_ENTRY_GROUP)
436
436
        self.entry_group_state_changed_match = (
437
437
            self.group.connect_to_signal(
438
 
                'StateChanged', self.entry_group_state_changed))
439
 
        logger.debug("Adding Zeroconf service '%s' of type '%s' ...",
440
 
                     self.name, self.type)
 
438
                "StateChanged", self.entry_group_state_changed))
 
439
        log.debug("Adding Zeroconf service '%s' of type '%s' ...",
 
440
                  self.name, self.type)
441
441
        self.group.AddService(
442
442
            self.interface,
443
443
            self.protocol,
450
450
 
451
451
    def entry_group_state_changed(self, state, error):
452
452
        """Derived from the Avahi example code"""
453
 
        logger.debug("Avahi entry group state change: %i", state)
 
453
        log.debug("Avahi entry group state change: %i", state)
454
454
 
455
455
        if state == avahi.ENTRY_GROUP_ESTABLISHED:
456
 
            logger.debug("Zeroconf service established.")
 
456
            log.debug("Zeroconf service established.")
457
457
        elif state == avahi.ENTRY_GROUP_COLLISION:
458
 
            logger.info("Zeroconf service name collision.")
 
458
            log.info("Zeroconf service name collision.")
459
459
            self.rename()
460
460
        elif state == avahi.ENTRY_GROUP_FAILURE:
461
 
            logger.critical("Avahi: Error in group state changed %s",
462
 
                            str(error))
 
461
            log.critical("Avahi: Error in group state changed %s",
 
462
                         str(error))
463
463
            raise AvahiGroupError("State changed: {!s}".format(error))
464
464
 
465
465
    def cleanup(self):
475
475
 
476
476
    def server_state_changed(self, state, error=None):
477
477
        """Derived from the Avahi example code"""
478
 
        logger.debug("Avahi server state change: %i", state)
 
478
        log.debug("Avahi server state change: %i", state)
479
479
        bad_states = {
480
480
            avahi.SERVER_INVALID: "Zeroconf server invalid",
481
481
            avahi.SERVER_REGISTERING: None,
485
485
        if state in bad_states:
486
486
            if bad_states[state] is not None:
487
487
                if error is None:
488
 
                    logger.error(bad_states[state])
 
488
                    log.error(bad_states[state])
489
489
                else:
490
 
                    logger.error(bad_states[state] + ": %r", error)
 
490
                    log.error(bad_states[state] + ": %r", error)
491
491
            self.cleanup()
492
492
        elif state == avahi.SERVER_RUNNING:
493
493
            try:
495
495
            except dbus.exceptions.DBusException as error:
496
496
                if (error.get_dbus_name()
497
497
                    == "org.freedesktop.Avahi.CollisionError"):
498
 
                    logger.info("Local Zeroconf service name"
499
 
                                " collision.")
 
498
                    log.info("Local Zeroconf service name collision.")
500
499
                    return self.rename(remove=False)
501
500
                else:
502
 
                    logger.critical("D-Bus Exception", exc_info=error)
 
501
                    log.critical("D-Bus Exception", exc_info=error)
503
502
                    self.cleanup()
504
503
                    os._exit(1)
505
504
        else:
506
505
            if error is None:
507
 
                logger.debug("Unknown state: %r", state)
 
506
                log.debug("Unknown state: %r", state)
508
507
            else:
509
 
                logger.debug("Unknown state: %r: %r", state, error)
 
508
                log.debug("Unknown state: %r: %r", state, error)
510
509
 
511
510
    def activate(self):
512
511
        """Derived from the Avahi example code"""
527
526
        ret = super(AvahiServiceToSyslog, self).rename(*args,
528
527
                                                       **kwargs)
529
528
        syslogger.setFormatter(logging.Formatter(
530
 
            'Mandos ({}) [%(process)d]: %(levelname)s: %(message)s'
 
529
            "Mandos ({}) [%(process)d]: %(levelname)s: %(message)s"
531
530
            .format(self.name)))
532
531
        return ret
533
532
 
563
562
    OPENPGP_FMT_RAW = 0         # gnutls/openpgp.h
564
563
 
565
564
    # Types
566
 
    class session_int(ctypes.Structure):
 
565
    class _session_int(ctypes.Structure):
567
566
        _fields_ = []
568
 
    session_t = ctypes.POINTER(session_int)
 
567
    session_t = ctypes.POINTER(_session_int)
569
568
 
570
569
    class certificate_credentials_st(ctypes.Structure):
571
570
        _fields_ = []
574
573
    certificate_type_t = ctypes.c_int
575
574
 
576
575
    class datum_t(ctypes.Structure):
577
 
        _fields_ = [('data', ctypes.POINTER(ctypes.c_ubyte)),
578
 
                    ('size', ctypes.c_uint)]
 
576
        _fields_ = [("data", ctypes.POINTER(ctypes.c_ubyte)),
 
577
                    ("size", ctypes.c_uint)]
579
578
 
580
 
    class openpgp_crt_int(ctypes.Structure):
 
579
    class _openpgp_crt_int(ctypes.Structure):
581
580
        _fields_ = []
582
 
    openpgp_crt_t = ctypes.POINTER(openpgp_crt_int)
 
581
    openpgp_crt_t = ctypes.POINTER(_openpgp_crt_int)
583
582
    openpgp_crt_fmt_t = ctypes.c_int  # gnutls/openpgp.h
584
583
    log_func = ctypes.CFUNCTYPE(None, ctypes.c_int, ctypes.c_char_p)
585
584
    credentials_type_t = ctypes.c_int
594
593
            # gnutls.strerror()
595
594
            self.code = code
596
595
            if message is None and code is not None:
597
 
                message = gnutls.strerror(code)
 
596
                message = gnutls.strerror(code).decode(
 
597
                    "utf-8", errors="replace")
598
598
            return super(gnutls.Error, self).__init__(
599
599
                message, *args)
600
600
 
601
601
    class CertificateSecurityError(Error):
602
602
        pass
603
603
 
 
604
    class PointerTo:
 
605
        def __init__(self, cls):
 
606
            self.cls = cls
 
607
 
 
608
        def from_param(self, obj):
 
609
            if not isinstance(obj, self.cls):
 
610
                raise TypeError("Not of type {}: {!r}"
 
611
                                .format(self.cls.__name__, obj))
 
612
            return ctypes.byref(obj.from_param(obj))
 
613
 
 
614
    class CastToVoidPointer:
 
615
        def __init__(self, cls):
 
616
            self.cls = cls
 
617
 
 
618
        def from_param(self, obj):
 
619
            if not isinstance(obj, self.cls):
 
620
                raise TypeError("Not of type {}: {!r}"
 
621
                                .format(self.cls.__name__, obj))
 
622
            return ctypes.cast(obj.from_param(obj), ctypes.c_void_p)
 
623
 
 
624
    class With_from_param:
 
625
        @classmethod
 
626
        def from_param(cls, obj):
 
627
            return obj._as_parameter_
 
628
 
604
629
    # Classes
605
 
    class Credentials:
 
630
    class Credentials(With_from_param):
606
631
        def __init__(self):
607
 
            self._c_object = gnutls.certificate_credentials_t()
608
 
            gnutls.certificate_allocate_credentials(
609
 
                ctypes.byref(self._c_object))
 
632
            self._as_parameter_ = gnutls.certificate_credentials_t()
 
633
            gnutls.certificate_allocate_credentials(self)
610
634
            self.type = gnutls.CRD_CERTIFICATE
611
635
 
612
636
        def __del__(self):
613
 
            gnutls.certificate_free_credentials(self._c_object)
 
637
            gnutls.certificate_free_credentials(self)
614
638
 
615
 
    class ClientSession:
 
639
    class ClientSession(With_from_param):
616
640
        def __init__(self, socket, credentials=None):
617
 
            self._c_object = gnutls.session_t()
 
641
            self._as_parameter_ = gnutls.session_t()
618
642
            gnutls_flags = gnutls.CLIENT
619
643
            if gnutls.check_version(b"3.5.6"):
620
644
                gnutls_flags |= gnutls.NO_TICKETS
621
645
            if gnutls.has_rawpk:
622
646
                gnutls_flags |= gnutls.ENABLE_RAWPK
623
 
            gnutls.init(ctypes.byref(self._c_object), gnutls_flags)
 
647
            gnutls.init(self, gnutls_flags)
624
648
            del gnutls_flags
625
 
            gnutls.set_default_priority(self._c_object)
626
 
            gnutls.transport_set_ptr(self._c_object, socket.fileno())
627
 
            gnutls.handshake_set_private_extensions(self._c_object,
628
 
                                                    True)
 
649
            gnutls.set_default_priority(self)
 
650
            gnutls.transport_set_ptr(self, socket.fileno())
 
651
            gnutls.handshake_set_private_extensions(self, True)
629
652
            self.socket = socket
630
653
            if credentials is None:
631
654
                credentials = gnutls.Credentials()
632
 
            gnutls.credentials_set(self._c_object, credentials.type,
633
 
                                   ctypes.cast(credentials._c_object,
634
 
                                               ctypes.c_void_p))
 
655
            gnutls.credentials_set(self, credentials.type,
 
656
                                   credentials)
635
657
            self.credentials = credentials
636
658
 
637
659
        def __del__(self):
638
 
            gnutls.deinit(self._c_object)
 
660
            gnutls.deinit(self)
639
661
 
640
662
        def handshake(self):
641
 
            return gnutls.handshake(self._c_object)
 
663
            return gnutls.handshake(self)
642
664
 
643
665
        def send(self, data):
644
666
            data = bytes(data)
645
667
            data_len = len(data)
646
668
            while data_len > 0:
647
 
                data_len -= gnutls.record_send(self._c_object,
648
 
                                               data[-data_len:],
 
669
                data_len -= gnutls.record_send(self, data[-data_len:],
649
670
                                               data_len)
650
671
 
651
672
        def bye(self):
652
 
            return gnutls.bye(self._c_object, gnutls.SHUT_RDWR)
 
673
            return gnutls.bye(self, gnutls.SHUT_RDWR)
653
674
 
654
675
    # Error handling functions
655
676
    def _error_code(result):
656
677
        """A function to raise exceptions on errors, suitable
657
 
        for the 'restype' attribute on ctypes functions"""
658
 
        if result >= 0:
 
678
        for the "restype" attribute on ctypes functions"""
 
679
        if result >= gnutls.E_SUCCESS:
659
680
            return result
660
681
        if result == gnutls.E_NO_CERTIFICATE_FOUND:
661
682
            raise gnutls.CertificateSecurityError(code=result)
664
685
    def _retry_on_error(result, func, arguments,
665
686
                        _error_code=_error_code):
666
687
        """A function to retry on some errors, suitable
667
 
        for the 'errcheck' attribute on ctypes functions"""
668
 
        while result < 0:
 
688
        for the "errcheck" attribute on ctypes functions"""
 
689
        while result < gnutls.E_SUCCESS:
669
690
            if result not in (gnutls.E_INTERRUPTED, gnutls.E_AGAIN):
670
691
                return _error_code(result)
671
692
            result = func(*arguments)
676
697
 
677
698
    # Functions
678
699
    priority_set_direct = _library.gnutls_priority_set_direct
679
 
    priority_set_direct.argtypes = [session_t, ctypes.c_char_p,
 
700
    priority_set_direct.argtypes = [ClientSession, ctypes.c_char_p,
680
701
                                    ctypes.POINTER(ctypes.c_char_p)]
681
702
    priority_set_direct.restype = _error_code
682
703
 
683
704
    init = _library.gnutls_init
684
 
    init.argtypes = [ctypes.POINTER(session_t), ctypes.c_int]
 
705
    init.argtypes = [PointerTo(ClientSession), ctypes.c_int]
685
706
    init.restype = _error_code
686
707
 
687
708
    set_default_priority = _library.gnutls_set_default_priority
688
 
    set_default_priority.argtypes = [session_t]
 
709
    set_default_priority.argtypes = [ClientSession]
689
710
    set_default_priority.restype = _error_code
690
711
 
691
712
    record_send = _library.gnutls_record_send
692
 
    record_send.argtypes = [session_t, ctypes.c_void_p,
 
713
    record_send.argtypes = [ClientSession, ctypes.c_void_p,
693
714
                            ctypes.c_size_t]
694
715
    record_send.restype = ctypes.c_ssize_t
695
716
    record_send.errcheck = _retry_on_error
697
718
    certificate_allocate_credentials = (
698
719
        _library.gnutls_certificate_allocate_credentials)
699
720
    certificate_allocate_credentials.argtypes = [
700
 
        ctypes.POINTER(certificate_credentials_t)]
 
721
        PointerTo(Credentials)]
701
722
    certificate_allocate_credentials.restype = _error_code
702
723
 
703
724
    certificate_free_credentials = (
704
725
        _library.gnutls_certificate_free_credentials)
705
 
    certificate_free_credentials.argtypes = [
706
 
        certificate_credentials_t]
 
726
    certificate_free_credentials.argtypes = [Credentials]
707
727
    certificate_free_credentials.restype = None
708
728
 
709
729
    handshake_set_private_extensions = (
710
730
        _library.gnutls_handshake_set_private_extensions)
711
 
    handshake_set_private_extensions.argtypes = [session_t,
 
731
    handshake_set_private_extensions.argtypes = [ClientSession,
712
732
                                                 ctypes.c_int]
713
733
    handshake_set_private_extensions.restype = None
714
734
 
715
735
    credentials_set = _library.gnutls_credentials_set
716
 
    credentials_set.argtypes = [session_t, credentials_type_t,
717
 
                                ctypes.c_void_p]
 
736
    credentials_set.argtypes = [ClientSession, credentials_type_t,
 
737
                                CastToVoidPointer(Credentials)]
718
738
    credentials_set.restype = _error_code
719
739
 
720
740
    strerror = _library.gnutls_strerror
722
742
    strerror.restype = ctypes.c_char_p
723
743
 
724
744
    certificate_type_get = _library.gnutls_certificate_type_get
725
 
    certificate_type_get.argtypes = [session_t]
 
745
    certificate_type_get.argtypes = [ClientSession]
726
746
    certificate_type_get.restype = _error_code
727
747
 
728
748
    certificate_get_peers = _library.gnutls_certificate_get_peers
729
 
    certificate_get_peers.argtypes = [session_t,
 
749
    certificate_get_peers.argtypes = [ClientSession,
730
750
                                      ctypes.POINTER(ctypes.c_uint)]
731
751
    certificate_get_peers.restype = ctypes.POINTER(datum_t)
732
752
 
739
759
    global_set_log_function.restype = None
740
760
 
741
761
    deinit = _library.gnutls_deinit
742
 
    deinit.argtypes = [session_t]
 
762
    deinit.argtypes = [ClientSession]
743
763
    deinit.restype = None
744
764
 
745
765
    handshake = _library.gnutls_handshake
746
 
    handshake.argtypes = [session_t]
747
 
    handshake.restype = _error_code
 
766
    handshake.argtypes = [ClientSession]
 
767
    handshake.restype = ctypes.c_int
748
768
    handshake.errcheck = _retry_on_error
749
769
 
750
770
    transport_set_ptr = _library.gnutls_transport_set_ptr
751
 
    transport_set_ptr.argtypes = [session_t, transport_ptr_t]
 
771
    transport_set_ptr.argtypes = [ClientSession, transport_ptr_t]
752
772
    transport_set_ptr.restype = None
753
773
 
754
774
    bye = _library.gnutls_bye
755
 
    bye.argtypes = [session_t, close_request_t]
756
 
    bye.restype = _error_code
 
775
    bye.argtypes = [ClientSession, close_request_t]
 
776
    bye.restype = ctypes.c_int
757
777
    bye.errcheck = _retry_on_error
758
778
 
759
779
    check_version = _library.gnutls_check_version
833
853
 
834
854
    if check_version(b"3.6.4"):
835
855
        certificate_type_get2 = _library.gnutls_certificate_type_get2
836
 
        certificate_type_get2.argtypes = [session_t, ctypes.c_int]
 
856
        certificate_type_get2.argtypes = [ClientSession, ctypes.c_int]
837
857
        certificate_type_get2.restype = _error_code
838
858
 
839
859
    # Remove non-public functions
855
875
    """A representation of a client host served by this server.
856
876
 
857
877
    Attributes:
858
 
    approved:   bool(); 'None' if not yet approved/disapproved
 
878
    approved:   bool(); None if not yet approved/disapproved
859
879
    approval_delay: datetime.timedelta(); Time to wait for approval
860
880
    approval_duration: datetime.timedelta(); Duration of one approval
861
881
    checker: multiprocessing.Process(); a running checker process used
862
 
             to see if the client lives. 'None' if no process is
 
882
             to see if the client lives. None if no process is
863
883
             running.
864
884
    checker_callback_tag: a GLib event source tag, or None
865
885
    checker_command: string; External command which is run to check
989
1009
            self.last_enabled = None
990
1010
            self.expires = None
991
1011
 
992
 
        logger.debug("Creating client %r", self.name)
993
 
        logger.debug("  Key ID: %s", self.key_id)
994
 
        logger.debug("  Fingerprint: %s", self.fingerprint)
 
1012
        log.debug("Creating client %r", self.name)
 
1013
        log.debug("  Key ID: %s", self.key_id)
 
1014
        log.debug("  Fingerprint: %s", self.fingerprint)
995
1015
        self.created = settings.get("created",
996
1016
                                    datetime.datetime.utcnow())
997
1017
 
1036
1056
        if not getattr(self, "enabled", False):
1037
1057
            return False
1038
1058
        if not quiet:
1039
 
            logger.info("Disabling client %s", self.name)
 
1059
            log.info("Disabling client %s", self.name)
1040
1060
        if getattr(self, "disable_initiator_tag", None) is not None:
1041
1061
            GLib.source_remove(self.disable_initiator_tag)
1042
1062
            self.disable_initiator_tag = None
1086
1106
            self.last_checker_status = returncode
1087
1107
            self.last_checker_signal = None
1088
1108
            if self.last_checker_status == 0:
1089
 
                logger.info("Checker for %(name)s succeeded",
1090
 
                            vars(self))
 
1109
                log.info("Checker for %(name)s succeeded", vars(self))
1091
1110
                self.checked_ok()
1092
1111
            else:
1093
 
                logger.info("Checker for %(name)s failed", vars(self))
 
1112
                log.info("Checker for %(name)s failed", vars(self))
1094
1113
        else:
1095
1114
            self.last_checker_status = -1
1096
1115
            self.last_checker_signal = -returncode
1097
 
            logger.warning("Checker for %(name)s crashed?",
1098
 
                           vars(self))
 
1116
            log.warning("Checker for %(name)s crashed?", vars(self))
1099
1117
        return False
1100
1118
 
1101
1119
    def checked_ok(self):
1135
1153
        # should be.
1136
1154
 
1137
1155
        if self.checker is not None and not self.checker.is_alive():
1138
 
            logger.warning("Checker was not alive; joining")
 
1156
            log.warning("Checker was not alive; joining")
1139
1157
            self.checker.join()
1140
1158
            self.checker = None
1141
1159
        # Start a new checker if needed
1147
1165
            try:
1148
1166
                command = self.checker_command % escaped_attrs
1149
1167
            except TypeError as error:
1150
 
                logger.error('Could not format string "%s"',
1151
 
                             self.checker_command,
1152
 
                             exc_info=error)
 
1168
                log.error('Could not format string "%s"',
 
1169
                          self.checker_command, exc_info=error)
1153
1170
                return True     # Try again later
1154
1171
            self.current_checker_command = command
1155
 
            logger.info("Starting checker %r for %s", command,
1156
 
                        self.name)
 
1172
            log.info("Starting checker %r for %s", command, self.name)
1157
1173
            # We don't need to redirect stdout and stderr, since
1158
1174
            # in normal mode, that is already done by daemon(),
1159
1175
            # and in debug mode we don't want to.  (Stdin is
1188
1204
            self.checker_callback_tag = None
1189
1205
        if getattr(self, "checker", None) is None:
1190
1206
            return
1191
 
        logger.debug("Stopping checker for %(name)s", vars(self))
 
1207
        log.debug("Stopping checker for %(name)s", vars(self))
1192
1208
        self.checker.terminate()
1193
1209
        self.checker = None
1194
1210
 
1221
1237
        func._dbus_name = func.__name__
1222
1238
        if func._dbus_name.endswith("_dbus_property"):
1223
1239
            func._dbus_name = func._dbus_name[:-14]
1224
 
        func._dbus_get_args_options = {'byte_arrays': byte_arrays}
 
1240
        func._dbus_get_args_options = {"byte_arrays": byte_arrays}
1225
1241
        return func
1226
1242
 
1227
1243
    return decorator
1316
1332
 
1317
1333
    @dbus.service.method(dbus.INTROSPECTABLE_IFACE,
1318
1334
                         out_signature="s",
1319
 
                         path_keyword='object_path',
1320
 
                         connection_keyword='connection')
 
1335
                         path_keyword="object_path",
 
1336
                         connection_keyword="connection")
1321
1337
    def Introspect(self, object_path, connection):
1322
1338
        """Overloading of standard D-Bus method.
1323
1339
 
1372
1388
            document.unlink()
1373
1389
        except (AttributeError, xml.dom.DOMException,
1374
1390
                xml.parsers.expat.ExpatError) as error:
1375
 
            logger.error("Failed to override Introspection method",
1376
 
                         exc_info=error)
 
1391
            log.error("Failed to override Introspection method",
 
1392
                      exc_info=error)
1377
1393
        return xmlstring
1378
1394
 
1379
1395
 
1476
1492
 
1477
1493
    @dbus.service.method(dbus.INTROSPECTABLE_IFACE,
1478
1494
                         out_signature="s",
1479
 
                         path_keyword='object_path',
1480
 
                         connection_keyword='connection')
 
1495
                         path_keyword="object_path",
 
1496
                         connection_keyword="connection")
1481
1497
    def Introspect(self, object_path, connection):
1482
1498
        """Overloading of standard D-Bus method.
1483
1499
 
1539
1555
            document.unlink()
1540
1556
        except (AttributeError, xml.dom.DOMException,
1541
1557
                xml.parsers.expat.ExpatError) as error:
1542
 
            logger.error("Failed to override Introspection method",
1543
 
                         exc_info=error)
 
1558
            log.error("Failed to override Introspection method",
 
1559
                      exc_info=error)
1544
1560
        return xmlstring
1545
1561
 
1546
1562
 
1578
1594
 
1579
1595
    @dbus.service.method(dbus.INTROSPECTABLE_IFACE,
1580
1596
                         out_signature="s",
1581
 
                         path_keyword='object_path',
1582
 
                         connection_keyword='connection')
 
1597
                         path_keyword="object_path",
 
1598
                         connection_keyword="connection")
1583
1599
    def Introspect(self, object_path, connection):
1584
1600
        """Overloading of standard D-Bus method.
1585
1601
 
1610
1626
            document.unlink()
1611
1627
        except (AttributeError, xml.dom.DOMException,
1612
1628
                xml.parsers.expat.ExpatError) as error:
1613
 
            logger.error("Failed to override Introspection method",
1614
 
                         exc_info=error)
 
1629
            log.error("Failed to override Introspection method",
 
1630
                      exc_info=error)
1615
1631
        return xmlstring
1616
1632
 
1617
1633
 
2251
2267
class ProxyClient:
2252
2268
    def __init__(self, child_pipe, key_id, fpr, address):
2253
2269
        self._pipe = child_pipe
2254
 
        self._pipe.send(('init', key_id, fpr, address))
 
2270
        self._pipe.send(("init", key_id, fpr, address))
2255
2271
        if not self._pipe.recv():
2256
2272
            raise KeyError(key_id or fpr)
2257
2273
 
2258
2274
    def __getattribute__(self, name):
2259
 
        if name == '_pipe':
 
2275
        if name == "_pipe":
2260
2276
            return super(ProxyClient, self).__getattribute__(name)
2261
 
        self._pipe.send(('getattr', name))
 
2277
        self._pipe.send(("getattr", name))
2262
2278
        data = self._pipe.recv()
2263
 
        if data[0] == 'data':
 
2279
        if data[0] == "data":
2264
2280
            return data[1]
2265
 
        if data[0] == 'function':
 
2281
        if data[0] == "function":
2266
2282
 
2267
2283
            def func(*args, **kwargs):
2268
 
                self._pipe.send(('funcall', name, args, kwargs))
 
2284
                self._pipe.send(("funcall", name, args, kwargs))
2269
2285
                return self._pipe.recv()[1]
2270
2286
 
2271
2287
            return func
2272
2288
 
2273
2289
    def __setattr__(self, name, value):
2274
 
        if name == '_pipe':
 
2290
        if name == "_pipe":
2275
2291
            return super(ProxyClient, self).__setattr__(name, value)
2276
 
        self._pipe.send(('setattr', name, value))
 
2292
        self._pipe.send(("setattr", name, value))
2277
2293
 
2278
2294
 
2279
2295
class ClientHandler(socketserver.BaseRequestHandler, object):
2284
2300
 
2285
2301
    def handle(self):
2286
2302
        with contextlib.closing(self.server.child_pipe) as child_pipe:
2287
 
            logger.info("TCP connection from: %s",
2288
 
                        str(self.client_address))
2289
 
            logger.debug("Pipe FD: %d",
2290
 
                         self.server.child_pipe.fileno())
 
2303
            log.info("TCP connection from: %s",
 
2304
                     str(self.client_address))
 
2305
            log.debug("Pipe FD: %d", self.server.child_pipe.fileno())
2291
2306
 
2292
2307
            session = gnutls.ClientSession(self.request)
2293
2308
 
2294
 
            # priority = ':'.join(("NONE", "+VERS-TLS1.1",
 
2309
            # priority = ":".join(("NONE", "+VERS-TLS1.1",
2295
2310
            #                       "+AES-256-CBC", "+SHA1",
2296
2311
            #                       "+COMP-NULL", "+CTYPE-OPENPGP",
2297
2312
            #                       "+DHE-DSS"))
2299
2314
            priority = self.server.gnutls_priority
2300
2315
            if priority is None:
2301
2316
                priority = "NORMAL"
2302
 
            gnutls.priority_set_direct(session._c_object,
2303
 
                                       priority.encode("utf-8"),
2304
 
                                       None)
 
2317
            gnutls.priority_set_direct(session,
 
2318
                                       priority.encode("utf-8"), None)
2305
2319
 
2306
2320
            # Start communication using the Mandos protocol
2307
2321
            # Get protocol number
2308
2322
            line = self.request.makefile().readline()
2309
 
            logger.debug("Protocol version: %r", line)
 
2323
            log.debug("Protocol version: %r", line)
2310
2324
            try:
2311
2325
                if int(line.strip().split()[0]) > 1:
2312
2326
                    raise RuntimeError(line)
2313
2327
            except (ValueError, IndexError, RuntimeError) as error:
2314
 
                logger.error("Unknown protocol version: %s", error)
 
2328
                log.error("Unknown protocol version: %s", error)
2315
2329
                return
2316
2330
 
2317
2331
            # Start GnuTLS connection
2318
2332
            try:
2319
2333
                session.handshake()
2320
2334
            except gnutls.Error as error:
2321
 
                logger.warning("Handshake failed: %s", error)
 
2335
                log.warning("Handshake failed: %s", error)
2322
2336
                # Do not run session.bye() here: the session is not
2323
2337
                # established.  Just abandon the request.
2324
2338
                return
2325
 
            logger.debug("Handshake succeeded")
 
2339
            log.debug("Handshake succeeded")
2326
2340
 
2327
2341
            approval_required = False
2328
2342
            try:
2332
2346
                        key_id = self.key_id(
2333
2347
                            self.peer_certificate(session))
2334
2348
                    except (TypeError, gnutls.Error) as error:
2335
 
                        logger.warning("Bad certificate: %s", error)
 
2349
                        log.warning("Bad certificate: %s", error)
2336
2350
                        return
2337
 
                    logger.debug("Key ID: %s", key_id)
 
2351
                    log.debug("Key ID: %s",
 
2352
                              key_id.decode("utf-8",
 
2353
                                            errors="replace"))
2338
2354
 
2339
2355
                else:
2340
2356
                    key_id = b""
2342
2358
                        fpr = self.fingerprint(
2343
2359
                            self.peer_certificate(session))
2344
2360
                    except (TypeError, gnutls.Error) as error:
2345
 
                        logger.warning("Bad certificate: %s", error)
 
2361
                        log.warning("Bad certificate: %s", error)
2346
2362
                        return
2347
 
                    logger.debug("Fingerprint: %s", fpr)
 
2363
                    log.debug("Fingerprint: %s", fpr)
2348
2364
 
2349
2365
                try:
2350
2366
                    client = ProxyClient(child_pipe, key_id, fpr,
2359
2375
 
2360
2376
                while True:
2361
2377
                    if not client.enabled:
2362
 
                        logger.info("Client %s is disabled",
2363
 
                                    client.name)
 
2378
                        log.info("Client %s is disabled", client.name)
2364
2379
                        if self.server.use_dbus:
2365
2380
                            # Emit D-Bus signal
2366
2381
                            client.Rejected("Disabled")
2370
2385
                        # We are approved or approval is disabled
2371
2386
                        break
2372
2387
                    elif client.approved is None:
2373
 
                        logger.info("Client %s needs approval",
2374
 
                                    client.name)
 
2388
                        log.info("Client %s needs approval",
 
2389
                                 client.name)
2375
2390
                        if self.server.use_dbus:
2376
2391
                            # Emit D-Bus signal
2377
2392
                            client.NeedApproval(
2378
2393
                                client.approval_delay.total_seconds()
2379
2394
                                * 1000, client.approved_by_default)
2380
2395
                    else:
2381
 
                        logger.warning("Client %s was not approved",
2382
 
                                       client.name)
 
2396
                        log.warning("Client %s was not approved",
 
2397
                                    client.name)
2383
2398
                        if self.server.use_dbus:
2384
2399
                            # Emit D-Bus signal
2385
2400
                            client.Rejected("Denied")
2393
2408
                    time2 = datetime.datetime.now()
2394
2409
                    if (time2 - time) >= delay:
2395
2410
                        if not client.approved_by_default:
2396
 
                            logger.warning("Client %s timed out while"
2397
 
                                           " waiting for approval",
2398
 
                                           client.name)
 
2411
                            log.warning("Client %s timed out while"
 
2412
                                        " waiting for approval",
 
2413
                                        client.name)
2399
2414
                            if self.server.use_dbus:
2400
2415
                                # Emit D-Bus signal
2401
2416
                                client.Rejected("Approval timed out")
2408
2423
                try:
2409
2424
                    session.send(client.secret)
2410
2425
                except gnutls.Error as error:
2411
 
                    logger.warning("gnutls send failed",
2412
 
                                   exc_info=error)
 
2426
                    log.warning("gnutls send failed", exc_info=error)
2413
2427
                    return
2414
2428
 
2415
 
                logger.info("Sending secret to %s", client.name)
 
2429
                log.info("Sending secret to %s", client.name)
2416
2430
                # bump the timeout using extended_timeout
2417
2431
                client.bump_timeout(client.extended_timeout)
2418
2432
                if self.server.use_dbus:
2425
2439
                try:
2426
2440
                    session.bye()
2427
2441
                except gnutls.Error as error:
2428
 
                    logger.warning("GnuTLS bye failed",
2429
 
                                   exc_info=error)
 
2442
                    log.warning("GnuTLS bye failed", exc_info=error)
2430
2443
 
2431
2444
    @staticmethod
2432
2445
    def peer_certificate(session):
2433
2446
        "Return the peer's certificate as a bytestring"
2434
2447
        try:
2435
 
            cert_type = gnutls.certificate_type_get2(session._c_object,
2436
 
                                                     gnutls.CTYPE_PEERS)
 
2448
            cert_type = gnutls.certificate_type_get2(
 
2449
                session, gnutls.CTYPE_PEERS)
2437
2450
        except AttributeError:
2438
 
            cert_type = gnutls.certificate_type_get(session._c_object)
 
2451
            cert_type = gnutls.certificate_type_get(session)
2439
2452
        if gnutls.has_rawpk:
2440
2453
            valid_cert_types = frozenset((gnutls.CRT_RAWPK,))
2441
2454
        else:
2442
2455
            valid_cert_types = frozenset((gnutls.CRT_OPENPGP,))
2443
2456
        # If not a valid certificate type...
2444
2457
        if cert_type not in valid_cert_types:
2445
 
            logger.info("Cert type %r not in %r", cert_type,
2446
 
                        valid_cert_types)
 
2458
            log.info("Cert type %r not in %r", cert_type,
 
2459
                     valid_cert_types)
2447
2460
            # ...return invalid data
2448
2461
            return b""
2449
2462
        list_size = ctypes.c_uint(1)
2450
2463
        cert_list = (gnutls.certificate_get_peers
2451
 
                     (session._c_object, ctypes.byref(list_size)))
 
2464
                     (session, ctypes.byref(list_size)))
2452
2465
        if not bool(cert_list) and list_size.value != 0:
2453
2466
            raise gnutls.Error("error getting peer certificate")
2454
2467
        if list_size.value == 0:
2568
2581
 
2569
2582
class IPv6_TCPServer(MultiprocessingMixInWithPipe,
2570
2583
                     socketserver.TCPServer):
2571
 
    """IPv6-capable TCP server.  Accepts 'None' as address and/or port
 
2584
    """IPv6-capable TCP server.  Accepts None as address and/or port
2572
2585
 
2573
2586
    Attributes:
2574
2587
        enabled:        Boolean; whether this server is activated yet
2625
2638
            if SO_BINDTODEVICE is None:
2626
2639
                # Fall back to a hard-coded value which seems to be
2627
2640
                # common enough.
2628
 
                logger.warning("SO_BINDTODEVICE not found, trying 25")
 
2641
                log.warning("SO_BINDTODEVICE not found, trying 25")
2629
2642
                SO_BINDTODEVICE = 25
2630
2643
            try:
2631
2644
                self.socket.setsockopt(
2633
2646
                    (self.interface + "\0").encode("utf-8"))
2634
2647
            except socket.error as error:
2635
2648
                if error.errno == errno.EPERM:
2636
 
                    logger.error("No permission to bind to"
2637
 
                                 " interface %s", self.interface)
 
2649
                    log.error("No permission to bind to interface %s",
 
2650
                              self.interface)
2638
2651
                elif error.errno == errno.ENOPROTOOPT:
2639
 
                    logger.error("SO_BINDTODEVICE not available;"
2640
 
                                 " cannot bind to interface %s",
2641
 
                                 self.interface)
 
2652
                    log.error("SO_BINDTODEVICE not available; cannot"
 
2653
                              " bind to interface %s", self.interface)
2642
2654
                elif error.errno == errno.ENODEV:
2643
 
                    logger.error("Interface %s does not exist,"
2644
 
                                 " cannot bind", self.interface)
 
2655
                    log.error("Interface %s does not exist, cannot"
 
2656
                              " bind", self.interface)
2645
2657
                else:
2646
2658
                    raise
2647
2659
        # Only bind(2) the socket if we really need to.
2726
2738
        request = parent_pipe.recv()
2727
2739
        command = request[0]
2728
2740
 
2729
 
        if command == 'init':
 
2741
        if command == "init":
2730
2742
            key_id = request[1].decode("ascii")
2731
2743
            fpr = request[2].decode("ascii")
2732
2744
            address = request[3]
2742
2754
                    client = c
2743
2755
                    break
2744
2756
            else:
2745
 
                logger.info("Client not found for key ID: %s, address"
2746
 
                            ": %s", key_id or fpr, address)
 
2757
                log.info("Client not found for key ID: %s, address:"
 
2758
                         " %s", key_id or fpr, address)
2747
2759
                if self.use_dbus:
2748
2760
                    # Emit D-Bus signal
2749
2761
                    mandos_dbus_service.ClientNotFound(key_id or fpr,
2762
2774
            # remove the old hook in favor of the new above hook on
2763
2775
            # same fileno
2764
2776
            return False
2765
 
        if command == 'funcall':
 
2777
        if command == "funcall":
2766
2778
            funcname = request[1]
2767
2779
            args = request[2]
2768
2780
            kwargs = request[3]
2769
2781
 
2770
 
            parent_pipe.send(('data', getattr(client_object,
 
2782
            parent_pipe.send(("data", getattr(client_object,
2771
2783
                                              funcname)(*args,
2772
2784
                                                        **kwargs)))
2773
2785
 
2774
 
        if command == 'getattr':
 
2786
        if command == "getattr":
2775
2787
            attrname = request[1]
2776
2788
            if isinstance(client_object.__getattribute__(attrname),
2777
2789
                          collections.abc.Callable):
2778
 
                parent_pipe.send(('function', ))
 
2790
                parent_pipe.send(("function", ))
2779
2791
            else:
2780
2792
                parent_pipe.send((
2781
 
                    'data', client_object.__getattribute__(attrname)))
 
2793
                    "data", client_object.__getattribute__(attrname)))
2782
2794
 
2783
 
        if command == 'setattr':
 
2795
        if command == "setattr":
2784
2796
            attrname = request[1]
2785
2797
            value = request[2]
2786
2798
            setattr(client_object, attrname, value)
2892
2904
def string_to_delta(interval):
2893
2905
    """Parse a string and return a datetime.timedelta
2894
2906
 
2895
 
    >>> string_to_delta('7d') == datetime.timedelta(7)
2896
 
    True
2897
 
    >>> string_to_delta('60s') == datetime.timedelta(0, 60)
2898
 
    True
2899
 
    >>> string_to_delta('60m') == datetime.timedelta(0, 3600)
2900
 
    True
2901
 
    >>> string_to_delta('24h') == datetime.timedelta(1)
2902
 
    True
2903
 
    >>> string_to_delta('1w') == datetime.timedelta(7)
2904
 
    True
2905
 
    >>> string_to_delta('5m 30s') == datetime.timedelta(0, 330)
 
2907
    >>> string_to_delta("7d") == datetime.timedelta(7)
 
2908
    True
 
2909
    >>> string_to_delta("60s") == datetime.timedelta(0, 60)
 
2910
    True
 
2911
    >>> string_to_delta("60m") == datetime.timedelta(0, 3600)
 
2912
    True
 
2913
    >>> string_to_delta("24h") == datetime.timedelta(1)
 
2914
    True
 
2915
    >>> string_to_delta("1w") == datetime.timedelta(7)
 
2916
    True
 
2917
    >>> string_to_delta("5m 30s") == datetime.timedelta(0, 330)
2906
2918
    True
2907
2919
    """
2908
2920
 
3112
3124
 
3113
3125
    if server_settings["servicename"] != "Mandos":
3114
3126
        syslogger.setFormatter(
3115
 
            logging.Formatter('Mandos ({}) [%(process)d]:'
3116
 
                              ' %(levelname)s: %(message)s'.format(
 
3127
            logging.Formatter("Mandos ({}) [%(process)d]:"
 
3128
                              " %(levelname)s: %(message)s".format(
3117
3129
                                  server_settings["servicename"])))
3118
3130
 
3119
3131
    # Parse config file with clients
3143
3155
        try:
3144
3156
            pidfile = codecs.open(pidfilename, "w", encoding="utf-8")
3145
3157
        except IOError as e:
3146
 
            logger.error("Could not open file %r", pidfilename,
3147
 
                         exc_info=e)
 
3158
            log.error("Could not open file %r", pidfilename,
 
3159
                      exc_info=e)
3148
3160
 
3149
3161
    for name, group in (("_mandos", "_mandos"),
3150
3162
                        ("mandos", "mandos"),
3161
3173
    try:
3162
3174
        os.setgid(gid)
3163
3175
        os.setuid(uid)
3164
 
        if debug:
3165
 
            logger.debug("Did setuid/setgid to {}:{}".format(uid,
3166
 
                                                             gid))
 
3176
        log.debug("Did setuid/setgid to %s:%s", uid, gid)
3167
3177
    except OSError as error:
3168
 
        logger.warning("Failed to setuid/setgid to {}:{}: {}"
3169
 
                       .format(uid, gid, os.strerror(error.errno)))
 
3178
        log.warning("Failed to setuid/setgid to %s:%s: %s", uid, gid,
 
3179
                    os.strerror(error.errno))
3170
3180
        if error.errno != errno.EPERM:
3171
3181
            raise
3172
3182
 
3179
3189
 
3180
3190
        @gnutls.log_func
3181
3191
        def debug_gnutls(level, string):
3182
 
            logger.debug("GnuTLS: %s", string[:-1])
 
3192
            log.debug("GnuTLS: %s",
 
3193
                      string[:-1].decode("utf-8", errors="replace"))
3183
3194
 
3184
3195
        gnutls.global_set_log_function(debug_gnutls)
3185
3196
 
3214
3225
                "se.bsnet.fukt.Mandos", bus,
3215
3226
                do_not_queue=True)
3216
3227
        except dbus.exceptions.DBusException as e:
3217
 
            logger.error("Disabling D-Bus:", exc_info=e)
 
3228
            log.error("Disabling D-Bus:", exc_info=e)
3218
3229
            use_dbus = False
3219
3230
            server_settings["use_dbus"] = False
3220
3231
            tcp_server.use_dbus = False
3305
3316
            os.remove(stored_state_path)
3306
3317
        except IOError as e:
3307
3318
            if e.errno == errno.ENOENT:
3308
 
                logger.warning("Could not load persistent state:"
3309
 
                               " {}".format(os.strerror(e.errno)))
 
3319
                log.warning("Could not load persistent state:"
 
3320
                            " %s", os.strerror(e.errno))
3310
3321
            else:
3311
 
                logger.critical("Could not load persistent state:",
3312
 
                                exc_info=e)
 
3322
                log.critical("Could not load persistent state:",
 
3323
                             exc_info=e)
3313
3324
                raise
3314
3325
        except EOFError as e:
3315
 
            logger.warning("Could not load persistent state: "
3316
 
                           "EOFError:",
3317
 
                           exc_info=e)
 
3326
            log.warning("Could not load persistent state: EOFError:",
 
3327
                        exc_info=e)
3318
3328
 
3319
3329
    with PGPEngine() as pgp:
3320
3330
        for client_name, client in clients_data.items():
3347
3357
            if client["enabled"]:
3348
3358
                if datetime.datetime.utcnow() >= client["expires"]:
3349
3359
                    if not client["last_checked_ok"]:
3350
 
                        logger.warning(
3351
 
                            "disabling client {} - Client never "
3352
 
                            "performed a successful checker".format(
3353
 
                                client_name))
 
3360
                        log.warning("disabling client %s - Client"
 
3361
                                    " never performed a successful"
 
3362
                                    " checker", client_name)
3354
3363
                        client["enabled"] = False
3355
3364
                    elif client["last_checker_status"] != 0:
3356
 
                        logger.warning(
3357
 
                            "disabling client {} - Client last"
3358
 
                            " checker failed with error code"
3359
 
                            " {}".format(
3360
 
                                client_name,
3361
 
                                client["last_checker_status"]))
 
3365
                        log.warning("disabling client %s - Client"
 
3366
                                    " last checker failed with error"
 
3367
                                    " code %s", client_name,
 
3368
                                    client["last_checker_status"])
3362
3369
                        client["enabled"] = False
3363
3370
                    else:
3364
3371
                        client["expires"] = (
3365
3372
                            datetime.datetime.utcnow()
3366
3373
                            + client["timeout"])
3367
 
                        logger.debug("Last checker succeeded,"
3368
 
                                     " keeping {} enabled".format(
3369
 
                                         client_name))
 
3374
                        log.debug("Last checker succeeded, keeping %s"
 
3375
                                  " enabled", client_name)
3370
3376
            try:
3371
3377
                client["secret"] = pgp.decrypt(
3372
3378
                    client["encrypted_secret"],
3373
3379
                    client_settings[client_name]["secret"])
3374
3380
            except PGPError:
3375
3381
                # If decryption fails, we use secret from new settings
3376
 
                logger.debug("Failed to decrypt {} old secret".format(
3377
 
                    client_name))
 
3382
                log.debug("Failed to decrypt %s old secret",
 
3383
                          client_name)
3378
3384
                client["secret"] = (client_settings[client_name]
3379
3385
                                    ["secret"])
3380
3386
 
3394
3400
            server_settings=server_settings)
3395
3401
 
3396
3402
    if not tcp_server.clients:
3397
 
        logger.warning("No clients defined")
 
3403
        log.warning("No clients defined")
3398
3404
 
3399
3405
    if not foreground:
3400
3406
        if pidfile is not None:
3403
3409
                with pidfile:
3404
3410
                    print(pid, file=pidfile)
3405
3411
            except IOError:
3406
 
                logger.error("Could not write to file %r with PID %d",
3407
 
                             pidfilename, pid)
 
3412
                log.error("Could not write to file %r with PID %d",
 
3413
                          pidfilename, pid)
3408
3414
        del pidfile
3409
3415
        del pidfilename
3410
3416
 
3560
3566
 
3561
3567
        try:
3562
3568
            with tempfile.NamedTemporaryFile(
3563
 
                    mode='wb',
 
3569
                    mode="wb",
3564
3570
                    suffix=".pickle",
3565
 
                    prefix='clients-',
 
3571
                    prefix="clients-",
3566
3572
                    dir=os.path.dirname(stored_state_path),
3567
3573
                    delete=False) as stored_state:
3568
3574
                pickle.dump((clients, client_settings), stored_state,
3576
3582
                except NameError:
3577
3583
                    pass
3578
3584
            if e.errno in (errno.ENOENT, errno.EACCES, errno.EEXIST):
3579
 
                logger.warning("Could not save persistent state: {}"
3580
 
                               .format(os.strerror(e.errno)))
 
3585
                log.warning("Could not save persistent state: %s",
 
3586
                            os.strerror(e.errno))
3581
3587
            else:
3582
 
                logger.warning("Could not save persistent state:",
3583
 
                               exc_info=e)
 
3588
                log.warning("Could not save persistent state:",
 
3589
                            exc_info=e)
3584
3590
                raise
3585
3591
 
3586
3592
        # Delete all clients, and settings from config
3612
3618
    if zeroconf:
3613
3619
        service.port = tcp_server.socket.getsockname()[1]
3614
3620
    if use_ipv6:
3615
 
        logger.info("Now listening on address %r, port %d,"
3616
 
                    " flowinfo %d, scope_id %d",
3617
 
                    *tcp_server.socket.getsockname())
 
3621
        log.info("Now listening on address %r, port %d, flowinfo %d,"
 
3622
                 " scope_id %d", *tcp_server.socket.getsockname())
3618
3623
    else:                       # IPv4
3619
 
        logger.info("Now listening on address %r, port %d",
3620
 
                    *tcp_server.socket.getsockname())
 
3624
        log.info("Now listening on address %r, port %d",
 
3625
                 *tcp_server.socket.getsockname())
3621
3626
 
3622
3627
    # service.interface = tcp_server.socket.getsockname()[3]
3623
3628
 
3627
3632
            try:
3628
3633
                service.activate()
3629
3634
            except dbus.exceptions.DBusException as error:
3630
 
                logger.critical("D-Bus Exception", exc_info=error)
 
3635
                log.critical("D-Bus Exception", exc_info=error)
3631
3636
                cleanup()
3632
3637
                sys.exit(1)
3633
3638
            # End of Avahi example code
3638
3643
            lambda *args, **kwargs: (tcp_server.handle_request
3639
3644
                                     (*args[2:], **kwargs) or True))
3640
3645
 
3641
 
        logger.debug("Starting main loop")
 
3646
        log.debug("Starting main loop")
3642
3647
        main_loop.run()
3643
3648
    except AvahiError as error:
3644
 
        logger.critical("Avahi Error", exc_info=error)
 
3649
        log.critical("Avahi Error", exc_info=error)
3645
3650
        cleanup()
3646
3651
        sys.exit(1)
3647
3652
    except KeyboardInterrupt:
3648
3653
        if debug:
3649
3654
            print("", file=sys.stderr)
3650
 
        logger.debug("Server received KeyboardInterrupt")
3651
 
    logger.debug("Server exiting")
 
3655
        log.debug("Server received KeyboardInterrupt")
 
3656
    log.debug("Server exiting")
3652
3657
    # Must run before the D-Bus bus name gets deregistered
3653
3658
    cleanup()
3654
3659
 
3655
3660
 
3656
 
def should_only_run_tests():
 
3661
def parse_test_args():
 
3662
    # type: () -> argparse.Namespace
3657
3663
    parser = argparse.ArgumentParser(add_help=False)
3658
 
    parser.add_argument("--check", action='store_true')
 
3664
    parser.add_argument("--check", action="store_true")
 
3665
    parser.add_argument("--prefix", )
3659
3666
    args, unknown_args = parser.parse_known_args()
3660
 
    run_tests = args.check
3661
 
    if run_tests:
3662
 
        # Remove --check argument from sys.argv
 
3667
    if args.check:
 
3668
        # Remove test options from sys.argv
3663
3669
        sys.argv[1:] = unknown_args
3664
 
    return run_tests
 
3670
    return args
3665
3671
 
3666
3672
# Add all tests from doctest strings
3667
3673
def load_tests(loader, tests, none):
3669
3675
    tests.addTests(doctest.DocTestSuite())
3670
3676
    return tests
3671
3677
 
3672
 
if __name__ == '__main__':
 
3678
if __name__ == "__main__":
 
3679
    options = parse_test_args()
3673
3680
    try:
3674
 
        if should_only_run_tests():
3675
 
            # Call using ./mandos --check [--verbose]
3676
 
            unittest.main()
 
3681
        if options.check:
 
3682
            extra_test_prefix = options.prefix
 
3683
            if extra_test_prefix is not None:
 
3684
                if not (unittest.main(argv=[""], exit=False)
 
3685
                        .result.wasSuccessful()):
 
3686
                    sys.exit(1)
 
3687
                class ExtraTestLoader(unittest.TestLoader):
 
3688
                    testMethodPrefix = extra_test_prefix
 
3689
                # Call using ./scriptname --test [--verbose]
 
3690
                unittest.main(argv=[""], testLoader=ExtraTestLoader())
 
3691
            else:
 
3692
                unittest.main(argv=[""])
3677
3693
        else:
3678
3694
            main()
3679
3695
    finally:
3680
3696
        logging.shutdown()
 
3697
 
 
3698
# Local Variables:
 
3699
# run-tests:
 
3700
# (lambda (&optional extra)
 
3701
#   (if (not (funcall run-tests-in-test-buffer default-directory
 
3702
#             extra))
 
3703
#       (funcall show-test-buffer-in-test-window)
 
3704
#     (funcall remove-test-window)
 
3705
#     (if extra (message "Extra tests run successfully!"))))
 
3706
# run-tests-in-test-buffer:
 
3707
# (lambda (dir &optional extra)
 
3708
#   (with-current-buffer (get-buffer-create "*Test*")
 
3709
#     (setq buffer-read-only nil
 
3710
#           default-directory dir)
 
3711
#     (erase-buffer)
 
3712
#     (compilation-mode))
 
3713
#   (let ((process-result
 
3714
#          (let ((inhibit-read-only t))
 
3715
#            (process-file-shell-command
 
3716
#             (funcall get-command-line extra) nil "*Test*"))))
 
3717
#     (and (numberp process-result)
 
3718
#          (= process-result 0))))
 
3719
# get-command-line:
 
3720
# (lambda (&optional extra)
 
3721
#   (let ((quoted-script
 
3722
#          (shell-quote-argument (funcall get-script-name))))
 
3723
#     (format
 
3724
#      (concat "%s --check" (if extra " --prefix=atest" ""))
 
3725
#      quoted-script)))
 
3726
# get-script-name:
 
3727
# (lambda ()
 
3728
#   (if (fboundp 'file-local-name)
 
3729
#       (file-local-name (buffer-file-name))
 
3730
#     (or (file-remote-p (buffer-file-name) 'localname)
 
3731
#         (buffer-file-name))))
 
3732
# remove-test-window:
 
3733
# (lambda ()
 
3734
#   (let ((test-window (get-buffer-window "*Test*")))
 
3735
#     (if test-window (delete-window test-window))))
 
3736
# show-test-buffer-in-test-window:
 
3737
# (lambda ()
 
3738
#   (when (not (get-buffer-window-list "*Test*"))
 
3739
#     (setq next-error-last-buffer (get-buffer "*Test*"))
 
3740
#     (let* ((side (if (>= (window-width) 146) 'right 'bottom))
 
3741
#            (display-buffer-overriding-action
 
3742
#             `((display-buffer-in-side-window) (side . ,side)
 
3743
#               (window-height . fit-window-to-buffer)
 
3744
#               (window-width . fit-window-to-buffer))))
 
3745
#       (display-buffer "*Test*"))))
 
3746
# eval:
 
3747
# (progn
 
3748
#   (let* ((run-extra-tests (lambda () (interactive)
 
3749
#                             (funcall run-tests t)))
 
3750
#          (inner-keymap `(keymap (116 . ,run-extra-tests))) ; t
 
3751
#          (outer-keymap `(keymap (3 . ,inner-keymap))))     ; C-c
 
3752
#     (setq minor-mode-overriding-map-alist
 
3753
#           (cons `(run-tests . ,outer-keymap)
 
3754
#                 minor-mode-overriding-map-alist)))
 
3755
#   (add-hook 'after-save-hook run-tests 90 t))
 
3756
# End: