/mandos/trunk : revision 1252

146

version = "1.8.14"

147

stored_state_file = "clients.pickle"

148

149

log = logging.getLogger(os.path.basename(sys.argv[0]))

149

logger = logging.getLogger()

150

logging.captureWarnings(True) # Show warnings via the logging system

151

syslogger = None

152

191

syslogger.setFormatter(logging.Formatter

192

("Mandos [%(process)d]: %(levelname)s:"

193

" %(message)s"))

194

log.addHandler(syslogger)

194

logger.addHandler(syslogger)

195

196

if debug:

197

console = logging.StreamHandler()

199

" [%(process)d]:"

200

" %(levelname)s:"

201

" %(message)s"))

202

log.addHandler(console)

203

log.setLevel(level)

202

logger.addHandler(console)

203

logger.setLevel(level)

204

205

206

class PGPError(Exception):

394

def rename(self, remove=True):

395

"""Derived from the Avahi example code"""

396

if self.rename_count >= self.max_renames:

397

log.critical("No suitable Zeroconf service name found"

398

" after %i retries, exiting.",

399

self.rename_count)

397

logger.critical("No suitable Zeroconf service name found"

398

" after %i retries, exiting.",

399

self.rename_count)

400

raise AvahiServiceError("Too many renames")

401

self.name = str(

402

self.server.GetAlternativeServiceName(self.name))

403

self.rename_count += 1

404

log.info("Changing Zeroconf service name to %r ...",

405

self.name)

404

logger.info("Changing Zeroconf service name to %r ...",

405

self.name)

406

if remove:

407

self.remove()

408

try:

410

except dbus.exceptions.DBusException as error:

411

if (error.get_dbus_name()

412

== "org.freedesktop.Avahi.CollisionError"):

413

log.info("Local Zeroconf service name collision.")

413

logger.info("Local Zeroconf service name collision.")

414

return self.rename(remove=False)

415

else:

416

log.critical("D-Bus Exception", exc_info=error)

416

logger.critical("D-Bus Exception", exc_info=error)

417

self.cleanup()

418

os._exit(1)

419

436

self.entry_group_state_changed_match = (

437

self.group.connect_to_signal(

438

"StateChanged", self.entry_group_state_changed))

439

log.debug("Adding Zeroconf service '%s' of type '%s' ...",

440

self.name, self.type)

439

logger.debug("Adding Zeroconf service '%s' of type '%s' ...",

440

self.name, self.type)

441

self.group.AddService(

442

self.interface,

443

self.protocol,

450

451

def entry_group_state_changed(self, state, error):

452

"""Derived from the Avahi example code"""

453

log.debug("Avahi entry group state change: %i", state)

453

logger.debug("Avahi entry group state change: %i", state)

454

455

if state == avahi.ENTRY_GROUP_ESTABLISHED:

456

log.debug("Zeroconf service established.")

456

logger.debug("Zeroconf service established.")

457

elif state == avahi.ENTRY_GROUP_COLLISION:

458

log.info("Zeroconf service name collision.")

458

logger.info("Zeroconf service name collision.")

459

self.rename()

460

elif state == avahi.ENTRY_GROUP_FAILURE:

461

log.critical("Avahi: Error in group state changed %s",

462

str(error))

461

logger.critical("Avahi: Error in group state changed %s",

462

str(error))

463

raise AvahiGroupError("State changed: {!s}".format(error))

464

465

def cleanup(self):

475

476

def server_state_changed(self, state, error=None):

477

"""Derived from the Avahi example code"""

478

log.debug("Avahi server state change: %i", state)

478

logger.debug("Avahi server state change: %i", state)

479

bad_states = {

480

avahi.SERVER_INVALID: "Zeroconf server invalid",

481

avahi.SERVER_REGISTERING: None,

485

if state in bad_states:

486

if bad_states[state] is not None:

487

if error is None:

488

log.error(bad_states[state])

488

logger.error(bad_states[state])

489

else:

490

log.error(bad_states[state] + ": %r", error)

490

logger.error(bad_states[state] + ": %r", error)

491

self.cleanup()

492

elif state == avahi.SERVER_RUNNING:

493

try:

495

except dbus.exceptions.DBusException as error:

496

if (error.get_dbus_name()

497

== "org.freedesktop.Avahi.CollisionError"):

498

log.info("Local Zeroconf service name collision.")

498

logger.info("Local Zeroconf service name"

499

" collision.")

499

500

return self.rename(remove=False)

500

501

else:

501

log.critical("D-Bus Exception", exc_info=error)

502

logger.critical("D-Bus Exception", exc_info=error)

502

503

self.cleanup()

503

504

os._exit(1)

504

505

else:

505

506

if error is None:

506

log.debug("Unknown state: %r", state)

507

logger.debug("Unknown state: %r", state)

507

508

else:

508

log.debug("Unknown state: %r: %r", state, error)

509

logger.debug("Unknown state: %r: %r", state, error)

509

510

511

def activate(self):

511

512

"""Derived from the Avahi example code"""

1009

1010

self.last_enabled = None

1010

1011

self.expires = None

1011

1012

log.debug("Creating client %r", self.name)

1013

log.debug(" Key ID: %s", self.key_id)

1014

log.debug(" Fingerprint: %s", self.fingerprint)

1013

logger.debug("Creating client %r", self.name)

1014

logger.debug(" Key ID: %s", self.key_id)

1015

logger.debug(" Fingerprint: %s", self.fingerprint)

1015

1016

self.created = settings.get("created",

1016

1017

datetime.datetime.utcnow())

1017

1018

1056

1057

if not getattr(self, "enabled", False):

1057

1058

return False

1058

1059

if not quiet:

1059

log.info("Disabling client %s", self.name)

1060

logger.info("Disabling client %s", self.name)

1060

1061

if getattr(self, "disable_initiator_tag", None) is not None:

1061

1062

GLib.source_remove(self.disable_initiator_tag)

1062

1063

self.disable_initiator_tag = None

1106

1107

self.last_checker_status = returncode

1107

1108

self.last_checker_signal = None

1108

1109

if self.last_checker_status == 0:

1109

log.info("Checker for %(name)s succeeded", vars(self))

1110

logger.info("Checker for %(name)s succeeded",

1111

vars(self))

1110

1112

self.checked_ok()

1111

1113

else:

1112

log.info("Checker for %(name)s failed", vars(self))

1114

logger.info("Checker for %(name)s failed", vars(self))

1113

1115

else:

1114

1116

self.last_checker_status = -1

1115

1117

self.last_checker_signal = -returncode

1116

log.warning("Checker for %(name)s crashed?", vars(self))

1118

logger.warning("Checker for %(name)s crashed?",

1119

vars(self))

1117

1120

return False

1118

1121

1119

1122

def checked_ok(self):

1153

1156

# should be.

1154

1157

1155

1158

if self.checker is not None and not self.checker.is_alive():

1156

log.warning("Checker was not alive; joining")

1159

logger.warning("Checker was not alive; joining")

1157

1160

self.checker.join()

1158

1161

self.checker = None

1159

1162

# Start a new checker if needed

1165

1168

try:

1166

1169

command = self.checker_command % escaped_attrs

1167

1170

except TypeError as error:

1168

log.error('Could not format string "%s"',

1169

self.checker_command, exc_info=error)

1171

logger.error('Could not format string "%s"',

1172

self.checker_command,

1173

exc_info=error)

1170

1174

return True # Try again later

1171

1175

self.current_checker_command = command

1172

log.info("Starting checker %r for %s", command, self.name)

1176

logger.info("Starting checker %r for %s", command,

1177

self.name)

1173

1178

# We don't need to redirect stdout and stderr, since

1174

1179

# in normal mode, that is already done by daemon(),

1175

1180

# and in debug mode we don't want to. (Stdin is

1204

1209

self.checker_callback_tag = None

1205

1210

if getattr(self, "checker", None) is None:

1206

1211

return

1207

log.debug("Stopping checker for %(name)s", vars(self))

1212

logger.debug("Stopping checker for %(name)s", vars(self))

1208

1213

self.checker.terminate()

1209

1214

self.checker = None

1210

1215

1388

1393

document.unlink()

1389

1394

except (AttributeError, xml.dom.DOMException,

1390

1395

xml.parsers.expat.ExpatError) as error:

1391

log.error("Failed to override Introspection method",

1392

exc_info=error)

1396

logger.error("Failed to override Introspection method",

1397

exc_info=error)

1393

1398

return xmlstring

1394

1399

1395

1400

1555

1560

document.unlink()

1556

1561

except (AttributeError, xml.dom.DOMException,

1557

1562

xml.parsers.expat.ExpatError) as error:

1558

log.error("Failed to override Introspection method",

1559

exc_info=error)

1563

logger.error("Failed to override Introspection method",

1564

exc_info=error)

1560

1565

return xmlstring

1561

1566

1562

1567

1626

1631

document.unlink()

1627

1632

except (AttributeError, xml.dom.DOMException,

1628

1633

xml.parsers.expat.ExpatError) as error:

1629

log.error("Failed to override Introspection method",

1630

exc_info=error)

1634

logger.error("Failed to override Introspection method",

1635

exc_info=error)

1631

1636

return xmlstring

1632

1637

1633

1638

2300

2305

2301

2306

def handle(self):

2302

2307

with contextlib.closing(self.server.child_pipe) as child_pipe:

2303

log.info("TCP connection from: %s",

2304

str(self.client_address))

2305

log.debug("Pipe FD: %d", self.server.child_pipe.fileno())

2308

logger.info("TCP connection from: %s",

2309

str(self.client_address))

2310

logger.debug("Pipe FD: %d",

2311

self.server.child_pipe.fileno())

2306

2312

2307

2313

session = gnutls.ClientSession(self.request)

2308

2314

2320

2326

# Start communication using the Mandos protocol

2321

2327

# Get protocol number

2322

2328

line = self.request.makefile().readline()

2323

log.debug("Protocol version: %r", line)

2329

logger.debug("Protocol version: %r", line)

2324

2330

try:

2325

2331

if int(line.strip().split()[0]) > 1:

2326

2332

raise RuntimeError(line)

2327

2333

except (ValueError, IndexError, RuntimeError) as error:

2328

log.error("Unknown protocol version: %s", error)

2334

logger.error("Unknown protocol version: %s", error)

2329

2335

return

2330

2336

2331

2337

# Start GnuTLS connection

2332

2338

try:

2333

2339

session.handshake()

2334

2340

except gnutls.Error as error:

2335

log.warning("Handshake failed: %s", error)

2341

logger.warning("Handshake failed: %s", error)

2336

2342

# Do not run session.bye() here: the session is not

2337

2343

# established. Just abandon the request.

2338

2344

return

2339

log.debug("Handshake succeeded")

2345

logger.debug("Handshake succeeded")

2340

2346

2341

2347

approval_required = False

2342

2348

try:

2346

2352

key_id = self.key_id(

2347

2353

self.peer_certificate(session))

2348

2354

except (TypeError, gnutls.Error) as error:

2349

log.warning("Bad certificate: %s", error)

2355

logger.warning("Bad certificate: %s", error)

2350

2356

return

2351

log.debug("Key ID: %s",

2352

key_id.decode("utf-8",

2353

errors="replace"))

2357

logger.debug("Key ID: %s",

2358

key_id.decode("utf-8",

2359

errors="replace"))

2354

2360

2355

2361

else:

2356

2362

key_id = b""

2358

2364

fpr = self.fingerprint(

2359

2365

self.peer_certificate(session))

2360

2366

except (TypeError, gnutls.Error) as error:

2361

log.warning("Bad certificate: %s", error)

2367

logger.warning("Bad certificate: %s", error)

2362

2368

return

2363

log.debug("Fingerprint: %s", fpr)

2369

logger.debug("Fingerprint: %s", fpr)

2364

2370

2365

2371

try:

2366

2372

client = ProxyClient(child_pipe, key_id, fpr,

2375

2381

2376

2382

while True:

2377

2383

if not client.enabled:

2378

log.info("Client %s is disabled", client.name)

2384

logger.info("Client %s is disabled",

2385

client.name)

2379

2386

if self.server.use_dbus:

2380

2387

# Emit D-Bus signal

2381

2388

client.Rejected("Disabled")

2385

2392

# We are approved or approval is disabled

2386

2393

break

2387

2394

elif client.approved is None:

2388

log.info("Client %s needs approval",

2389

client.name)

2395

logger.info("Client %s needs approval",

2396

client.name)

2390

2397

if self.server.use_dbus:

2391

2398

# Emit D-Bus signal

2392

2399

client.NeedApproval(

2393

2400

client.approval_delay.total_seconds()

2394

2401

* 1000, client.approved_by_default)

2395

2402

else:

2396

log.warning("Client %s was not approved",

2397

client.name)

2403

logger.warning("Client %s was not approved",

2404

client.name)

2398

2405

if self.server.use_dbus:

2399

2406

# Emit D-Bus signal

2400

2407

client.Rejected("Denied")

2408

2415

time2 = datetime.datetime.now()

2409

2416

if (time2 - time) >= delay:

2410

2417

if not client.approved_by_default:

2411

log.warning("Client %s timed out while"

2412

" waiting for approval",

2413

client.name)

2418

logger.warning("Client %s timed out while"

2419

" waiting for approval",

2420

client.name)

2414

2421

if self.server.use_dbus:

2415

2422

# Emit D-Bus signal

2416

2423

client.Rejected("Approval timed out")

2423

2430

try:

2424

2431

session.send(client.secret)

2425

2432

except gnutls.Error as error:

2426

log.warning("gnutls send failed", exc_info=error)

2433

logger.warning("gnutls send failed",

2434

exc_info=error)

2427

2435

return

2428

2436

2429

log.info("Sending secret to %s", client.name)

2437

logger.info("Sending secret to %s", client.name)

2430

2438

# bump the timeout using extended_timeout

2431

2439

client.bump_timeout(client.extended_timeout)

2432

2440

if self.server.use_dbus:

2439

2447

try:

2440

2448

session.bye()

2441

2449

except gnutls.Error as error:

2442

log.warning("GnuTLS bye failed", exc_info=error)

2450

logger.warning("GnuTLS bye failed",

2451

exc_info=error)

2443

2452

2444

2453

@staticmethod

2445

2454

def peer_certificate(session):

2455

2464

valid_cert_types = frozenset((gnutls.CRT_OPENPGP,))

2456

2465

# If not a valid certificate type...

2457

2466

if cert_type not in valid_cert_types:

2458

log.info("Cert type %r not in %r", cert_type,

2459

valid_cert_types)

2467

logger.info("Cert type %r not in %r", cert_type,

2468

valid_cert_types)

2460

2469

# ...return invalid data

2461

2470

return b""

2462

2471

list_size = ctypes.c_uint(1)

2638

2647

if SO_BINDTODEVICE is None:

2639

2648

# Fall back to a hard-coded value which seems to be

2640

2649

# common enough.

2641

log.warning("SO_BINDTODEVICE not found, trying 25")

2650

logger.warning("SO_BINDTODEVICE not found, trying 25")

2642

2651

SO_BINDTODEVICE = 25

2643

2652

try:

2644

2653

self.socket.setsockopt(

2646

2655

(self.interface + "\0").encode("utf-8"))

2647

2656

except socket.error as error:

2648

2657

if error.errno == errno.EPERM:

2649

log.error("No permission to bind to interface %s",

2650

self.interface)

2658

logger.error("No permission to bind to"

2659

" interface %s", self.interface)

2651

2660

elif error.errno == errno.ENOPROTOOPT:

2652

log.error("SO_BINDTODEVICE not available; cannot"

2653

" bind to interface %s", self.interface)

2661

logger.error("SO_BINDTODEVICE not available;"

2662

" cannot bind to interface %s",

2663

self.interface)

2654

2664

elif error.errno == errno.ENODEV:

2655

log.error("Interface %s does not exist, cannot"

2656

" bind", self.interface)

2665

logger.error("Interface %s does not exist,"

2666

" cannot bind", self.interface)

2657

2667

else:

2658

2668

raise

2659

2669

# Only bind(2) the socket if we really need to.

2754

2764

client = c

2755

2765

break

2756

2766

else:

2757

log.info("Client not found for key ID: %s, address:"

2758

" %s", key_id or fpr, address)

2767

logger.info("Client not found for key ID: %s, address"

2768

": %s", key_id or fpr, address)

2759

2769

if self.use_dbus:

2760

2770

# Emit D-Bus signal

2761

2771

mandos_dbus_service.ClientNotFound(key_id or fpr,

3155

3165

try:

3156

3166

pidfile = codecs.open(pidfilename, "w", encoding="utf-8")

3157

3167

except IOError as e:

3158

log.error("Could not open file %r", pidfilename,

3159

exc_info=e)

3168

logger.error("Could not open file %r", pidfilename,

3169

exc_info=e)

3160

3170

3161

3171

for name, group in (("_mandos", "_mandos"),

3162

3172

("mandos", "mandos"),

3173

3183

try:

3174

3184

os.setgid(gid)

3175

3185

os.setuid(uid)

3176

log.debug("Did setuid/setgid to %s:%s", uid, gid)

3186

if debug:

3187

logger.debug("Did setuid/setgid to {}:{}".format(uid,

3188

gid))

3177

3189

except OSError as error:

3178

log.warning("Failed to setuid/setgid to %s:%s: %s", uid, gid,

3179

os.strerror(error.errno))

3190

logger.warning("Failed to setuid/setgid to {}:{}: {}"

3191

.format(uid, gid, os.strerror(error.errno)))

3180

3192

if error.errno != errno.EPERM:

3181

3193

raise

3182

3194

3189

3201

3190

3202

@gnutls.log_func

3191

3203

def debug_gnutls(level, string):

3192

log.debug("GnuTLS: %s",

3193

string[:-1].decode("utf-8", errors="replace"))

3204

logger.debug("GnuTLS: %s",

3205

string[:-1].decode("utf-8",

3206

errors="replace"))

3194

3207

3195

3208

gnutls.global_set_log_function(debug_gnutls)

3196

3209

3225

3238

"se.bsnet.fukt.Mandos", bus,

3226

3239

do_not_queue=True)

3227

3240

except dbus.exceptions.DBusException as e:

3228

log.error("Disabling D-Bus:", exc_info=e)

3241

logger.error("Disabling D-Bus:", exc_info=e)

3229

3242

use_dbus = False

3230

3243

server_settings["use_dbus"] = False

3231

3244

tcp_server.use_dbus = False

3316

3329

os.remove(stored_state_path)

3317

3330

except IOError as e:

3318

3331

if e.errno == errno.ENOENT:

3319

log.warning("Could not load persistent state:"

3320

" %s", os.strerror(e.errno))

3332

logger.warning("Could not load persistent state:"

3333

" {}".format(os.strerror(e.errno)))

3321

3334

else:

3322

log.critical("Could not load persistent state:",

3323

exc_info=e)

3335

logger.critical("Could not load persistent state:",

3336

exc_info=e)

3324

3337

raise

3325

3338

except EOFError as e:

3326

log.warning("Could not load persistent state: EOFError:",

3327

exc_info=e)

3339

logger.warning("Could not load persistent state: "

3340

"EOFError:",

3341

exc_info=e)

3328

3342

3329

3343

with PGPEngine() as pgp:

3330

3344

for client_name, client in clients_data.items():

3357

3371

if client["enabled"]:

3358

3372

if datetime.datetime.utcnow() >= client["expires"]:

3359

3373

if not client["last_checked_ok"]:

3360

log.warning("disabling client %s - Client"

3361

" never performed a successful"

3362

" checker", client_name)

3374

logger.warning(

3375

"disabling client {} - Client never "

3376

"performed a successful checker".format(

3377

client_name))

3363

3378

client["enabled"] = False

3364

3379

elif client["last_checker_status"] != 0:

3365

log.warning("disabling client %s - Client"

3366

" last checker failed with error"

3367

" code %s", client_name,

3368

client["last_checker_status"])

3380

logger.warning(

3381

"disabling client {} - Client last"

3382

" checker failed with error code"

3383

" {}".format(

3384

client_name,

3385

client["last_checker_status"]))

3369

3386

client["enabled"] = False

3370

3387

else:

3371

3388

client["expires"] = (

3372

3389

datetime.datetime.utcnow()

3373

3390

+ client["timeout"])

3374

log.debug("Last checker succeeded, keeping %s"

3375

" enabled", client_name)

3391

logger.debug("Last checker succeeded,"

3392

" keeping {} enabled".format(

3393

client_name))

3376

3394

try:

3377

3395

client["secret"] = pgp.decrypt(

3378

3396

client["encrypted_secret"],

3379

3397

client_settings[client_name]["secret"])

3380

3398

except PGPError:

3381

3399

# If decryption fails, we use secret from new settings

3382

log.debug("Failed to decrypt %s old secret",

3383

client_name)

3400

logger.debug("Failed to decrypt {} old secret".format(

3401

client_name))

3384

3402

client["secret"] = (client_settings[client_name]

3385

3403

["secret"])

3386

3404

3400

3418

server_settings=server_settings)

3401

3419

3402

3420

if not tcp_server.clients:

3403

log.warning("No clients defined")

3421

logger.warning("No clients defined")

3404

3422

3405

3423

if not foreground:

3406

3424

if pidfile is not None:

3409

3427

with pidfile:

3410

3428

print(pid, file=pidfile)

3411

3429

except IOError:

3412

log.error("Could not write to file %r with PID %d",

3413

pidfilename, pid)

3430

logger.error("Could not write to file %r with PID %d",

3431

pidfilename, pid)

3414

3432

del pidfile

3415

3433

del pidfilename

3416

3434

3582

3600

except NameError:

3583

3601

pass

3584

3602

if e.errno in (errno.ENOENT, errno.EACCES, errno.EEXIST):

3585

log.warning("Could not save persistent state: %s",

3586

os.strerror(e.errno))

3603

logger.warning("Could not save persistent state: {}"

3604

.format(os.strerror(e.errno)))

3587

3605

else:

3588

log.warning("Could not save persistent state:",

3589

exc_info=e)

3606

logger.warning("Could not save persistent state:",

3607

exc_info=e)

3590

3608

raise

3591

3609

3592

3610

# Delete all clients, and settings from config

3618

3636

if zeroconf:

3619

3637

service.port = tcp_server.socket.getsockname()[1]

3620

3638

if use_ipv6:

3621

log.info("Now listening on address %r, port %d, flowinfo %d,"

3622

" scope_id %d", *tcp_server.socket.getsockname())

3639

logger.info("Now listening on address %r, port %d,"

3640

" flowinfo %d, scope_id %d",

3641

*tcp_server.socket.getsockname())

3623

3642

else: # IPv4

3624

log.info("Now listening on address %r, port %d",

3625

*tcp_server.socket.getsockname())

3643

logger.info("Now listening on address %r, port %d",

3644

*tcp_server.socket.getsockname())

3626

3645

3627

3646

# service.interface = tcp_server.socket.getsockname()[3]

3628

3647

3632

3651

try:

3633

3652

service.activate()

3634

3653

except dbus.exceptions.DBusException as error:

3635

log.critical("D-Bus Exception", exc_info=error)

3654

logger.critical("D-Bus Exception", exc_info=error)

3636

3655

cleanup()

3637

3656

sys.exit(1)

3638

3657

# End of Avahi example code

3643

3662

lambda *args, **kwargs: (tcp_server.handle_request

3644

3663

(*args[2:], **kwargs) or True))

3645

3664

3646

log.debug("Starting main loop")

3665

logger.debug("Starting main loop")

3647

3666

main_loop.run()

3648

3667

except AvahiError as error:

3649

log.critical("Avahi Error", exc_info=error)

3668

logger.critical("Avahi Error", exc_info=error)

3650

3669

cleanup()

3651

3670

sys.exit(1)

3652

3671

except KeyboardInterrupt:

3653

3672

if debug:

3654

3673

print("", file=sys.stderr)

3655

log.debug("Server received KeyboardInterrupt")

3656

log.debug("Server exiting")

3674

logger.debug("Server received KeyboardInterrupt")

3675

logger.debug("Server exiting")

3657

3676

# Must run before the D-Bus bus name gets deregistered

3658

3677

cleanup()

3659

3678