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.",
397
log.critical("No suitable Zeroconf service name found"
398
" after %i retries, exiting.",
400
400
raise AvahiServiceError("Too many renames")
402
402
self.server.GetAlternativeServiceName(self.name))
403
403
self.rename_count += 1
404
logger.info("Changing Zeroconf service name to %r ...",
404
log.info("Changing Zeroconf service name to %r ...",
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)
416
logger.critical("D-Bus Exception", exc_info=error)
416
log.critical("D-Bus Exception", exc_info=error)
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)
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.")
460
460
elif state == avahi.ENTRY_GROUP_FAILURE:
461
logger.critical("Avahi: Error in group state changed %s",
461
log.critical("Avahi: Error in group state changed %s",
463
463
raise AvahiGroupError("State changed: {!s}".format(error))
465
465
def cleanup(self):
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)
480
480
avahi.SERVER_INVALID: "Zeroconf server invalid",
481
481
avahi.SERVER_REGISTERING: None,
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"
498
log.info("Local Zeroconf service name collision.")
500
499
return self.rename(remove=False)
502
logger.critical("D-Bus Exception", exc_info=error)
501
log.critical("D-Bus Exception", exc_info=error)
506
505
if error is None:
507
logger.debug("Unknown state: %r", state)
506
log.debug("Unknown state: %r", state)
509
logger.debug("Unknown state: %r: %r", state, error)
508
log.debug("Unknown state: %r: %r", state, error)
511
510
def activate(self):
512
511
"""Derived from the Avahi example code"""
962
961
# key_id() and fingerprint() functions
963
962
client["key_id"] = (section.get("key_id", "").upper()
964
963
.replace(" ", ""))
965
client["fingerprint"] = (section["fingerprint"].upper()
964
client["fingerprint"] = (section.get("fingerprint",
966
966
.replace(" ", ""))
967
if not (client["key_id"] or client["fingerprint"]):
968
log.error("Skipping client %s without key_id or"
969
" fingerprint", client_name)
970
del settings[client_name]
967
972
if "secret" in section:
968
973
client["secret"] = codecs.decode(section["secret"]
969
974
.encode("utf-8"),
1010
1015
self.last_enabled = None
1011
1016
self.expires = None
1013
logger.debug("Creating client %r", self.name)
1014
logger.debug(" Key ID: %s", self.key_id)
1015
logger.debug(" Fingerprint: %s", self.fingerprint)
1018
log.debug("Creating client %r", self.name)
1019
log.debug(" Key ID: %s", self.key_id)
1020
log.debug(" Fingerprint: %s", self.fingerprint)
1016
1021
self.created = settings.get("created",
1017
1022
datetime.datetime.utcnow())
1057
1061
if not getattr(self, "enabled", False):
1060
logger.info("Disabling client %s", self.name)
1064
log.info("Disabling client %s", self.name)
1061
1065
if getattr(self, "disable_initiator_tag", None) is not None:
1062
1066
GLib.source_remove(self.disable_initiator_tag)
1063
1067
self.disable_initiator_tag = None
1075
1079
def __del__(self):
1078
def init_checker(self):
1079
# Schedule a new checker to be started an 'interval' from now,
1080
# and every interval from then on.
1082
def init_checker(self, randomize_start=False):
1083
# Schedule a new checker to be started a randomly selected
1084
# time (a fraction of 'interval') from now. This spreads out
1085
# the startup of checkers over time when the server is
1081
1087
if self.checker_initiator_tag is not None:
1082
1088
GLib.source_remove(self.checker_initiator_tag)
1089
interval_milliseconds = int(self.interval.total_seconds()
1092
delay_milliseconds = random.randrange(
1093
interval_milliseconds + 1)
1095
delay_milliseconds = interval_milliseconds
1083
1096
self.checker_initiator_tag = GLib.timeout_add(
1084
random.randrange(int(self.interval.total_seconds() * 1000
1087
# Schedule a disable() when 'timeout' has passed
1097
delay_milliseconds, self.start_checker, randomize_start)
1098
delay = datetime.timedelta(0, 0, 0, delay_milliseconds)
1099
# A checker might take up to an 'interval' of time, so we can
1100
# expire at the soonest one interval after a checker was
1101
# started. Since the initial checker is delayed, the expire
1102
# time might have to be extended.
1103
now = datetime.datetime.utcnow()
1104
self.expires = now + delay + self.interval
1105
# Schedule a disable() at expire time
1088
1106
if self.disable_initiator_tag is not None:
1089
1107
GLib.source_remove(self.disable_initiator_tag)
1090
1108
self.disable_initiator_tag = GLib.timeout_add(
1091
int(self.timeout.total_seconds() * 1000), self.disable)
1092
# Also start a new checker *right now*.
1093
self.start_checker()
1109
int((self.expires - now).total_seconds() * 1000),
1095
1112
def checker_callback(self, source, condition, connection,
1107
1124
self.last_checker_status = returncode
1108
1125
self.last_checker_signal = None
1109
1126
if self.last_checker_status == 0:
1110
logger.info("Checker for %(name)s succeeded",
1127
log.info("Checker for %(name)s succeeded", vars(self))
1112
1128
self.checked_ok()
1114
logger.info("Checker for %(name)s failed", vars(self))
1130
log.info("Checker for %(name)s failed", vars(self))
1116
1132
self.last_checker_status = -1
1117
1133
self.last_checker_signal = -returncode
1118
logger.warning("Checker for %(name)s crashed?",
1134
log.warning("Checker for %(name)s crashed?", vars(self))
1122
1137
def checked_ok(self):
1169
1184
command = self.checker_command % escaped_attrs
1170
1185
except TypeError as error:
1171
logger.error('Could not format string "%s"',
1172
self.checker_command,
1186
log.error('Could not format string "%s"',
1187
self.checker_command, exc_info=error)
1174
1188
return True # Try again later
1175
1189
self.current_checker_command = command
1176
logger.info("Starting checker %r for %s", command,
1190
log.info("Starting checker %r for %s", command, self.name)
1178
1191
# We don't need to redirect stdout and stderr, since
1179
1192
# in normal mode, that is already done by daemon(),
1180
1193
# and in debug mode we don't want to. (Stdin is
1199
1212
GLib.IOChannel.unix_new(pipe[0].fileno()),
1200
1213
GLib.PRIORITY_DEFAULT, GLib.IO_IN,
1201
1214
self.checker_callback, pipe[0], command)
1215
if start_was_randomized:
1216
# We were started after a random delay; Schedule a new
1217
# checker to be started an 'interval' from now, and every
1218
# interval from then on.
1219
now = datetime.datetime.utcnow()
1220
self.checker_initiator_tag = GLib.timeout_add(
1221
int(self.interval.total_seconds() * 1000),
1223
self.expires = max(self.expires, now + self.interval)
1224
# Don't start a new checker again after same random delay
1202
1226
# Re-run this periodically if run by GLib.timeout_add
2306
2330
def handle(self):
2307
2331
with contextlib.closing(self.server.child_pipe) as child_pipe:
2308
logger.info("TCP connection from: %s",
2309
str(self.client_address))
2310
logger.debug("Pipe FD: %d",
2311
self.server.child_pipe.fileno())
2332
log.info("TCP connection from: %s",
2333
str(self.client_address))
2334
log.debug("Pipe FD: %d", self.server.child_pipe.fileno())
2313
2336
session = gnutls.ClientSession(self.request)
2326
2349
# Start communication using the Mandos protocol
2327
2350
# Get protocol number
2328
2351
line = self.request.makefile().readline()
2329
logger.debug("Protocol version: %r", line)
2352
log.debug("Protocol version: %r", line)
2331
2354
if int(line.strip().split()[0]) > 1:
2332
2355
raise RuntimeError(line)
2333
2356
except (ValueError, IndexError, RuntimeError) as error:
2334
logger.error("Unknown protocol version: %s", error)
2357
log.error("Unknown protocol version: %s", error)
2337
2360
# Start GnuTLS connection
2339
2362
session.handshake()
2340
2363
except gnutls.Error as error:
2341
logger.warning("Handshake failed: %s", error)
2364
log.warning("Handshake failed: %s", error)
2342
2365
# Do not run session.bye() here: the session is not
2343
2366
# established. Just abandon the request.
2345
logger.debug("Handshake succeeded")
2368
log.debug("Handshake succeeded")
2347
2370
approval_required = False
2364
2387
fpr = self.fingerprint(
2365
2388
self.peer_certificate(session))
2366
2389
except (TypeError, gnutls.Error) as error:
2367
logger.warning("Bad certificate: %s", error)
2390
log.warning("Bad certificate: %s", error)
2369
logger.debug("Fingerprint: %s", fpr)
2392
log.debug("Fingerprint: %s", fpr)
2372
2395
client = ProxyClient(child_pipe, key_id, fpr,
2392
2414
# We are approved or approval is disabled
2394
2416
elif client.approved is None:
2395
logger.info("Client %s needs approval",
2417
log.info("Client %s needs approval",
2397
2419
if self.server.use_dbus:
2398
2420
# Emit D-Bus signal
2399
2421
client.NeedApproval(
2400
2422
client.approval_delay.total_seconds()
2401
2423
* 1000, client.approved_by_default)
2403
logger.warning("Client %s was not approved",
2425
log.warning("Client %s was not approved",
2405
2427
if self.server.use_dbus:
2406
2428
# Emit D-Bus signal
2407
2429
client.Rejected("Denied")
2431
2453
session.send(client.secret)
2432
2454
except gnutls.Error as error:
2433
logger.warning("gnutls send failed",
2455
log.warning("gnutls send failed", exc_info=error)
2437
logger.info("Sending secret to %s", client.name)
2458
log.info("Sending secret to %s", client.name)
2438
2459
# bump the timeout using extended_timeout
2439
2460
client.bump_timeout(client.extended_timeout)
2440
2461
if self.server.use_dbus:
2464
2484
valid_cert_types = frozenset((gnutls.CRT_OPENPGP,))
2465
2485
# If not a valid certificate type...
2466
2486
if cert_type not in valid_cert_types:
2467
logger.info("Cert type %r not in %r", cert_type,
2487
log.info("Cert type %r not in %r", cert_type,
2469
2489
# ...return invalid data
2471
2491
list_size = ctypes.c_uint(1)
2655
2675
(self.interface + "\0").encode("utf-8"))
2656
2676
except socket.error as error:
2657
2677
if error.errno == errno.EPERM:
2658
logger.error("No permission to bind to"
2659
" interface %s", self.interface)
2678
log.error("No permission to bind to interface %s",
2660
2680
elif error.errno == errno.ENOPROTOOPT:
2661
logger.error("SO_BINDTODEVICE not available;"
2662
" cannot bind to interface %s",
2681
log.error("SO_BINDTODEVICE not available; cannot"
2682
" bind to interface %s", self.interface)
2664
2683
elif error.errno == errno.ENODEV:
2665
logger.error("Interface %s does not exist,"
2666
" cannot bind", self.interface)
2684
log.error("Interface %s does not exist, cannot"
2685
" bind", self.interface)
2669
2688
# Only bind(2) the socket if we really need to.
2767
logger.info("Client not found for key ID: %s, address"
2768
": %s", key_id or fpr, address)
2786
log.info("Client not found for key ID: %s, address:"
2787
" %s", key_id or fpr, address)
2769
2788
if self.use_dbus:
2770
2789
# Emit D-Bus signal
2771
2790
mandos_dbus_service.ClientNotFound(key_id or fpr,
3166
3185
pidfile = codecs.open(pidfilename, "w", encoding="utf-8")
3167
3186
except IOError as e:
3168
logger.error("Could not open file %r", pidfilename,
3187
log.error("Could not open file %r", pidfilename,
3171
3190
for name, group in (("_mandos", "_mandos"),
3172
3191
("mandos", "mandos"),
3187
logger.debug("Did setuid/setgid to {}:{}".format(uid,
3205
log.debug("Did setuid/setgid to %s:%s", uid, gid)
3189
3206
except OSError as error:
3190
logger.warning("Failed to setuid/setgid to {}:{}: {}"
3191
.format(uid, gid, os.strerror(error.errno)))
3207
log.warning("Failed to setuid/setgid to %s:%s: %s", uid, gid,
3208
os.strerror(error.errno))
3192
3209
if error.errno != errno.EPERM:
3238
3255
"se.bsnet.fukt.Mandos", bus,
3239
3256
do_not_queue=True)
3240
3257
except dbus.exceptions.DBusException as e:
3241
logger.error("Disabling D-Bus:", exc_info=e)
3258
log.error("Disabling D-Bus:", exc_info=e)
3242
3259
use_dbus = False
3243
3260
server_settings["use_dbus"] = False
3244
3261
tcp_server.use_dbus = False
3329
3346
os.remove(stored_state_path)
3330
3347
except IOError as e:
3331
3348
if e.errno == errno.ENOENT:
3332
logger.warning("Could not load persistent state:"
3333
" {}".format(os.strerror(e.errno)))
3349
log.warning("Could not load persistent state:"
3350
" %s", os.strerror(e.errno))
3335
logger.critical("Could not load persistent state:",
3352
log.critical("Could not load persistent state:",
3338
3355
except EOFError as e:
3339
logger.warning("Could not load persistent state: "
3356
log.warning("Could not load persistent state: EOFError:",
3343
3359
with PGPEngine() as pgp:
3344
3360
for client_name, client in clients_data.items():
3371
3387
if client["enabled"]:
3372
3388
if datetime.datetime.utcnow() >= client["expires"]:
3373
3389
if not client["last_checked_ok"]:
3375
"disabling client {} - Client never "
3376
"performed a successful checker".format(
3390
log.warning("disabling client %s - Client"
3391
" never performed a successful"
3392
" checker", client_name)
3378
3393
client["enabled"] = False
3379
3394
elif client["last_checker_status"] != 0:
3381
"disabling client {} - Client last"
3382
" checker failed with error code"
3385
client["last_checker_status"]))
3395
log.warning("disabling client %s - Client"
3396
" last checker failed with error"
3397
" code %s", client_name,
3398
client["last_checker_status"])
3386
3399
client["enabled"] = False
3388
3401
client["expires"] = (
3389
3402
datetime.datetime.utcnow()
3390
3403
+ client["timeout"])
3391
logger.debug("Last checker succeeded,"
3392
" keeping {} enabled".format(
3404
log.debug("Last checker succeeded, keeping %s"
3405
" enabled", client_name)
3395
3407
client["secret"] = pgp.decrypt(
3396
3408
client["encrypted_secret"],
3397
3409
client_settings[client_name]["secret"])
3398
3410
except PGPError:
3399
3411
# If decryption fails, we use secret from new settings
3400
logger.debug("Failed to decrypt {} old secret".format(
3412
log.debug("Failed to decrypt %s old secret",
3402
3414
client["secret"] = (client_settings[client_name]
3600
3612
except NameError:
3602
3614
if e.errno in (errno.ENOENT, errno.EACCES, errno.EEXIST):
3603
logger.warning("Could not save persistent state: {}"
3604
.format(os.strerror(e.errno)))
3615
log.warning("Could not save persistent state: %s",
3616
os.strerror(e.errno))
3606
logger.warning("Could not save persistent state:",
3618
log.warning("Could not save persistent state:",
3610
3622
# Delete all clients, and settings from config
3637
3649
service.port = tcp_server.socket.getsockname()[1]
3639
logger.info("Now listening on address %r, port %d,"
3640
" flowinfo %d, scope_id %d",
3641
*tcp_server.socket.getsockname())
3651
log.info("Now listening on address %r, port %d, flowinfo %d,"
3652
" scope_id %d", *tcp_server.socket.getsockname())
3643
logger.info("Now listening on address %r, port %d",
3644
*tcp_server.socket.getsockname())
3654
log.info("Now listening on address %r, port %d",
3655
*tcp_server.socket.getsockname())
3646
3657
# service.interface = tcp_server.socket.getsockname()[3]
3662
3673
lambda *args, **kwargs: (tcp_server.handle_request
3663
3674
(*args[2:], **kwargs) or True))
3665
logger.debug("Starting main loop")
3676
log.debug("Starting main loop")
3666
3677
main_loop.run()
3667
3678
except AvahiError as error:
3668
logger.critical("Avahi Error", exc_info=error)
3679
log.critical("Avahi Error", exc_info=error)
3671
3682
except KeyboardInterrupt:
3673
3684
print("", file=sys.stderr)
3674
logger.debug("Server received KeyboardInterrupt")
3675
logger.debug("Server exiting")
3685
log.debug("Server received KeyboardInterrupt")
3686
log.debug("Server exiting")
3676
3687
# Must run before the D-Bus bus name gets deregistered
3680
def should_only_run_tests():
3691
def parse_test_args():
3692
# type: () -> argparse.Namespace
3681
3693
parser = argparse.ArgumentParser(add_help=False)
3682
3694
parser.add_argument("--check", action="store_true")
3695
parser.add_argument("--prefix", )
3683
3696
args, unknown_args = parser.parse_known_args()
3684
run_tests = args.check
3686
# Remove --check argument from sys.argv
3698
# Remove test options from sys.argv
3687
3699
sys.argv[1:] = unknown_args
3690
3702
# Add all tests from doctest strings
3691
3703
def load_tests(loader, tests, none):
3696
3708
if __name__ == "__main__":
3709
options = parse_test_args()
3698
if should_only_run_tests():
3699
# Call using ./mandos --check [--verbose]
3712
extra_test_prefix = options.prefix
3713
if extra_test_prefix is not None:
3714
if not (unittest.main(argv=[""], exit=False)
3715
.result.wasSuccessful()):
3717
class ExtraTestLoader(unittest.TestLoader):
3718
testMethodPrefix = extra_test_prefix
3719
# Call using ./scriptname --test [--verbose]
3720
unittest.main(argv=[""], testLoader=ExtraTestLoader())
3722
unittest.main(argv=[""])
3704
3726
logging.shutdown()
3730
# (lambda (&optional extra)
3731
# (if (not (funcall run-tests-in-test-buffer default-directory
3733
# (funcall show-test-buffer-in-test-window)
3734
# (funcall remove-test-window)
3735
# (if extra (message "Extra tests run successfully!"))))
3736
# run-tests-in-test-buffer:
3737
# (lambda (dir &optional extra)
3738
# (with-current-buffer (get-buffer-create "*Test*")
3739
# (setq buffer-read-only nil
3740
# default-directory dir)
3742
# (compilation-mode))
3743
# (let ((process-result
3744
# (let ((inhibit-read-only t))
3745
# (process-file-shell-command
3746
# (funcall get-command-line extra) nil "*Test*"))))
3747
# (and (numberp process-result)
3748
# (= process-result 0))))
3750
# (lambda (&optional extra)
3751
# (let ((quoted-script
3752
# (shell-quote-argument (funcall get-script-name))))
3754
# (concat "%s --check" (if extra " --prefix=atest" ""))
3758
# (if (fboundp 'file-local-name)
3759
# (file-local-name (buffer-file-name))
3760
# (or (file-remote-p (buffer-file-name) 'localname)
3761
# (buffer-file-name))))
3762
# remove-test-window:
3764
# (let ((test-window (get-buffer-window "*Test*")))
3765
# (if test-window (delete-window test-window))))
3766
# show-test-buffer-in-test-window:
3768
# (when (not (get-buffer-window-list "*Test*"))
3769
# (setq next-error-last-buffer (get-buffer "*Test*"))
3770
# (let* ((side (if (>= (window-width) 146) 'right 'bottom))
3771
# (display-buffer-overriding-action
3772
# `((display-buffer-in-side-window) (side . ,side)
3773
# (window-height . fit-window-to-buffer)
3774
# (window-width . fit-window-to-buffer))))
3775
# (display-buffer "*Test*"))))
3778
# (let* ((run-extra-tests (lambda () (interactive)
3779
# (funcall run-tests t)))
3780
# (inner-keymap `(keymap (116 . ,run-extra-tests))) ; t
3781
# (outer-keymap `(keymap (3 . ,inner-keymap)))) ; C-c
3782
# (setq minor-mode-overriding-map-alist
3783
# (cons `(run-tests . ,outer-keymap)
3784
# minor-mode-overriding-map-alist)))
3785
# (add-hook 'after-save-hook run-tests 90 t))