/mandos/release

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

« back to all changes in this revision

Viewing changes to mandos

  • Committer: Teddy Hogeborn
  • Date: 2011-10-22 00:46:35 UTC
  • mto: (237.7.67 trunk)
  • mto: This revision was merged to the branch mainline in revision 290.
  • Revision ID: teddy@recompile.se-20111022004635-3hey47pvet46yccr
* Makefile (run-server): Remove obsolete warning.
* mandos: Clean up and demystify logging.  Add time stamp to console
          debug log messages.
  (AvahiServiceToSyslog): New; only to adjust syslog format.
  (AvahiService.rename): Don't touch syslog logger.
* mandos.xml (BUGS): Remove note about timestamps on console log.

Show diffs side-by-side

added added

removed removed

Lines of Context:
mandos
83
83
        SO_BINDTODEVICE = None
84
84
 
85
85
 
86
 
version = "1.3.1"
 
86
version = "1.4.1"
87
87
 
88
 
#logger = logging.getLogger('mandos')
89
 
logger = logging.Logger('mandos')
 
88
logger = logging.getLogger()
90
89
syslogger = (logging.handlers.SysLogHandler
91
90
             (facility = logging.handlers.SysLogHandler.LOG_DAEMON,
92
91
              address = str("/dev/log")))
96
95
logger.addHandler(syslogger)
97
96
 
98
97
console = logging.StreamHandler()
99
 
console.setFormatter(logging.Formatter('%(name)s [%(process)d]:'
 
98
console.setFormatter(logging.Formatter('%(asctime)s %(name)s'
 
99
                                       ' [%(process)d]:'
100
100
                                       ' %(levelname)s:'
101
101
                                       ' %(message)s'))
102
102
logger.addHandler(console)
103
103
 
 
104
 
104
105
class AvahiError(Exception):
105
106
    def __init__(self, value, *args, **kwargs):
106
107
        self.value = value
164
165
                            .GetAlternativeServiceName(self.name))
165
166
        logger.info("Changing Zeroconf service name to %r ...",
166
167
                    self.name)
167
 
        syslogger.setFormatter(logging.Formatter
168
 
                               ('Mandos (%s) [%%(process)d]:'
169
 
                                ' %%(levelname)s: %%(message)s'
170
 
                                % self.name))
171
168
        self.remove()
172
169
        try:
173
170
            self.add()
193
190
                avahi.DBUS_INTERFACE_ENTRY_GROUP)
194
191
        self.entry_group_state_changed_match = (
195
192
            self.group.connect_to_signal(
196
 
                'StateChanged', self .entry_group_state_changed))
 
193
                'StateChanged', self.entry_group_state_changed))
197
194
        logger.debug("Adding Zeroconf service '%s' of type '%s' ...",
198
195
                     self.name, self.type)
199
196
        self.group.AddService(
265
262
                                 self.server_state_changed)
266
263
        self.server_state_changed(self.server.GetState())
267
264
 
 
265
class AvahiServiceToSyslog(AvahiService):
 
266
    def rename(self):
 
267
        """Add the new name to the syslog messages"""
 
268
        ret = AvahiService.rename(self)
 
269
        syslogger.setFormatter(logging.Formatter
 
270
                               ('Mandos (%s) [%%(process)d]:'
 
271
                                ' %%(levelname)s: %%(message)s'
 
272
                                % self.name))
 
273
        return ret
268
274
 
269
275
def _timedelta_to_milliseconds(td):
270
276
    "Convert a datetime.timedelta() to milliseconds"
464
470
        if timeout is None:
465
471
            timeout = self.timeout
466
472
        self.last_checked_ok = datetime.datetime.utcnow()
467
 
        gobject.source_remove(self.disable_initiator_tag)
468
 
        self.expires = datetime.datetime.utcnow() + timeout
469
 
        self.disable_initiator_tag = (gobject.timeout_add
470
 
                                      (_timedelta_to_milliseconds
471
 
                                       (timeout), self.disable))
 
473
        if self.disable_initiator_tag is not None:
 
474
            gobject.source_remove(self.disable_initiator_tag)
 
475
        if getattr(self, "enabled", False):
 
476
            self.disable_initiator_tag = (gobject.timeout_add
 
477
                                          (_timedelta_to_milliseconds
 
478
                                           (timeout), self.disable))
 
479
            self.expires = datetime.datetime.utcnow() + timeout
472
480
    
473
481
    def need_approval(self):
474
482
        self.last_approval_request = datetime.datetime.utcnow()
891
899
        """ Modify a variable so that it's a property which announces
892
900
        its changes to DBus.
893
901
 
894
 
        transform_fun: Function that takes a value and transforms it
895
 
                       to a D-Bus type.
 
902
        transform_fun: Function that takes a value and a variant_level
 
903
                       and transforms it to a D-Bus type.
896
904
        dbus_name: D-Bus name of the variable
897
905
        type_func: Function that transform the value before sending it
898
906
                   to the D-Bus.  Default: no transform
899
907
        variant_level: D-Bus variant level.  Default: 1
900
908
        """
901
 
        real_value = [None,]
 
909
        attrname = "_{0}".format(dbus_name)
902
910
        def setter(self, value):
903
 
            old_value = real_value[0]
904
 
            real_value[0] = value
905
911
            if hasattr(self, "dbus_object_path"):
906
 
                if type_func(old_value) != type_func(real_value[0]):
907
 
                    dbus_value = transform_func(type_func
908
 
                                                (real_value[0]),
909
 
                                                variant_level)
 
912
                if (not hasattr(self, attrname) or
 
913
                    type_func(getattr(self, attrname, None))
 
914
                    != type_func(value)):
 
915
                    dbus_value = transform_func(type_func(value),
 
916
                                                variant_level
 
917
                                                =variant_level)
910
918
                    self.PropertyChanged(dbus.String(dbus_name),
911
919
                                         dbus_value)
 
920
            setattr(self, attrname, value)
912
921
        
913
 
        return property(lambda self: real_value[0], setter)
 
922
        return property(lambda self: getattr(self, attrname), setter)
914
923
    
915
924
    
916
925
    expires = notifychangeproperty(datetime_to_dbus, "Expires")
1187
1196
        gobject.source_remove(self.disable_initiator_tag)
1188
1197
        self.disable_initiator_tag = None
1189
1198
        self.expires = None
1190
 
        time_to_die = (self.
1191
 
                       _timedelta_to_milliseconds((self
1192
 
                                                   .last_checked_ok
1193
 
                                                   + self.timeout)
1194
 
                                                  - datetime.datetime
1195
 
                                                  .utcnow()))
 
1199
        time_to_die = _timedelta_to_milliseconds((self
 
1200
                                                  .last_checked_ok
 
1201
                                                  + self.timeout)
 
1202
                                                 - datetime.datetime
 
1203
                                                 .utcnow())
1196
1204
        if time_to_die <= 0:
1197
1205
            # The timeout has passed
1198
1206
            self.disable()
1394
1402
                        return
1395
1403
                    
1396
1404
                    #wait until timeout or approved
1397
 
                    #x = float(client
1398
 
                    #          ._timedelta_to_milliseconds(delay))
1399
1405
                    time = datetime.datetime.now()
1400
1406
                    client.changedstate.acquire()
1401
1407
                    (client.changedstate.wait
1430
1436
                    sent_size += sent
1431
1437
                
1432
1438
                logger.info("Sending secret to %s", client.name)
1433
 
                # bump the timeout as if seen
 
1439
                # bump the timeout using extended_timeout
1434
1440
                client.checked_ok(client.extended_timeout)
1435
1441
                if self.server.use_dbus:
1436
1442
                    # Emit D-Bus signal
1516
1522
        except:
1517
1523
            self.handle_error(request, address)
1518
1524
        self.close_request(request)
1519
 
            
 
1525
    
1520
1526
    def process_request(self, request, address):
1521
1527
        """Start a new process to process the request."""
1522
 
        multiprocessing.Process(target = self.sub_process_main,
1523
 
                                args = (request, address)).start()
 
1528
        proc = multiprocessing.Process(target = self.sub_process_main,
 
1529
                                       args = (request,
 
1530
                                               address))
 
1531
        proc.start()
 
1532
        return proc
1524
1533
 
1525
1534
 
1526
1535
class MultiprocessingMixInWithPipe(MultiprocessingMixIn, object):
1532
1541
        """
1533
1542
        parent_pipe, self.child_pipe = multiprocessing.Pipe()
1534
1543
        
1535
 
        super(MultiprocessingMixInWithPipe,
1536
 
              self).process_request(request, client_address)
 
1544
        proc = MultiprocessingMixIn.process_request(self, request,
 
1545
                                                    client_address)
1537
1546
        self.child_pipe.close()
1538
 
        self.add_pipe(parent_pipe)
 
1547
        self.add_pipe(parent_pipe, proc)
1539
1548
    
1540
 
    def add_pipe(self, parent_pipe):
 
1549
    def add_pipe(self, parent_pipe, proc):
1541
1550
        """Dummy function; override as necessary"""
1542
1551
        raise NotImplementedError
1543
1552
 
1631
1640
    def server_activate(self):
1632
1641
        if self.enabled:
1633
1642
            return socketserver.TCPServer.server_activate(self)
 
1643
    
1634
1644
    def enable(self):
1635
1645
        self.enabled = True
1636
 
    def add_pipe(self, parent_pipe):
 
1646
    
 
1647
    def add_pipe(self, parent_pipe, proc):
1637
1648
        # Call "handle_ipc" for both data and EOF events
1638
1649
        gobject.io_add_watch(parent_pipe.fileno(),
1639
1650
                             gobject.IO_IN | gobject.IO_HUP,
1640
1651
                             functools.partial(self.handle_ipc,
1641
1652
                                               parent_pipe =
1642
 
                                               parent_pipe))
1643
 
        
 
1653
                                               parent_pipe,
 
1654
                                               proc = proc))
 
1655
    
1644
1656
    def handle_ipc(self, source, condition, parent_pipe=None,
1645
 
                   client_object=None):
 
1657
                   proc = None, client_object=None):
1646
1658
        condition_names = {
1647
1659
            gobject.IO_IN: "IN",   # There is data to read.
1648
1660
            gobject.IO_OUT: "OUT", # Data can be written (without
1657
1669
                                       for cond, name in
1658
1670
                                       condition_names.iteritems()
1659
1671
                                       if cond & condition)
1660
 
        # error or the other end of multiprocessing.Pipe has closed
 
1672
        # error, or the other end of multiprocessing.Pipe has closed
1661
1673
        if condition & (gobject.IO_ERR | condition & gobject.IO_HUP):
 
1674
            # Wait for other process to exit
 
1675
            proc.join()
1662
1676
            return False
1663
1677
        
1664
1678
        # Read a request from the child
1688
1702
                                 functools.partial(self.handle_ipc,
1689
1703
                                                   parent_pipe =
1690
1704
                                                   parent_pipe,
 
1705
                                                   proc = proc,
1691
1706
                                                   client_object =
1692
1707
                                                   client))
1693
1708
            parent_pipe.send(True)
1961
1976
            raise error
1962
1977
    
1963
1978
    if not debug and not debuglevel:
1964
 
        syslogger.setLevel(logging.WARNING)
1965
 
        console.setLevel(logging.WARNING)
 
1979
        logger.setLevel(logging.WARNING)
1966
1980
    if debuglevel:
1967
1981
        level = getattr(logging, debuglevel.upper())
1968
 
        syslogger.setLevel(level)
1969
 
        console.setLevel(level)
 
1982
        logger.setLevel(level)
1970
1983
    
1971
1984
    if debug:
 
1985
        logger.setLevel(logging.DEBUG)
1972
1986
        # Enable all possible GnuTLS debugging
1973
1987
        
1974
1988
        # "Use a log level over 10 to enable all debugging options."
2015
2029
            server_settings["use_dbus"] = False
2016
2030
            tcp_server.use_dbus = False
2017
2031
    protocol = avahi.PROTO_INET6 if use_ipv6 else avahi.PROTO_INET
2018
 
    service = AvahiService(name = server_settings["servicename"],
2019
 
                           servicetype = "_mandos._tcp",
2020
 
                           protocol = protocol, bus = bus)
 
2032
    service = AvahiServiceToSyslog(name =
 
2033
                                   server_settings["servicename"],
 
2034
                                   servicetype = "_mandos._tcp",
 
2035
                                   protocol = protocol, bus = bus)
2021
2036
    if server_settings["interface"]:
2022
2037
        service.interface = (if_nametoindex
2023
2038
                             (str(server_settings["interface"])))
2129
2144
        "Cleanup function; run on exit"
2130
2145
        service.cleanup()
2131
2146
        
 
2147
        multiprocessing.active_children()
2132
2148
        while tcp_server.clients:
2133
2149
            client = tcp_server.clients.pop()
2134
2150
            if use_dbus: