Coverage for src/lib/server.py: 19%

2import datetime as dt

3from socket import socket as Socket, timeout as SocketTimeout, gaierror as SocketGetaddrinfo, gethostname, gethostbyname, create_server, AF_INET, AF_INET6, SOCK_STREAM, SOCK_DGRAM, SOL_SOCKET, SO_REUSEADDR, SO_BROADCAST

4from selectors import DefaultSelector, EVENT_READ

5from ssl import TLSVersion, SSLContext, PROTOCOL_TLS_SERVER, PROTOCOL_TLS_CLIENT, CERT_NONE

6from struct import unpack, error as StructError

7from base64 import b64encode, b64decode

8from uuid import uuid4

9from os import path, getenv, getpid, mkdir, remove

10from logging import getLogger

12from cryptography.hazmat.primitives import serialization, hashes

13from cryptography.hazmat.primitives.asymmetric import padding

14from cryptography.fernet import Fernet

15from cryptography.exceptions import InvalidSignature

17from lib.client import Client, Action

18from lib.address_book import AddressBook

19from lib.helper import is_valid_uuid, binary_encode, binary_decode, password_key_derivation

20from lib.mail import Mail, Queue as MailQueue, Database as MailDatabase

21from lib.network import Network, RawCommandsType, SslHandshakeError

22from lib.cash import Cash

23from lib.contact import Contact

24from lib.overlay import Node, Distance

27VERSION = 1

28SSL_HANDSHAKE_WAIT = 0.3

29SSL_HANDSHAKE_TIMEOUT = 5

30SSL_MINIMUM_VERSION = TLSVersion.TLSv1_2

32class Server(Network):

33 _config: dict

34 _selectors: DefaultSelector

35 _main_server_socket: Socket

36 _discovery_socket: Socket

37 _ipc_server_socket: Socket

38 _address_book: AddressBook

39 _mail_queue: MailQueue

40 _mail_db: MailDatabase

41 _hostname: str

42 _lan_ip: str

43 _clients: list[Client]

44 _local_node: Node

45 _public_key_b64: str

46 _pid_file_path: str

47 _wrote_pid_file: bool

48 _client_auth_timeout: dt.timedelta

49 _client_action_retention_time: dt.timedelta

50 _contact: Contact

52 def __init__(self, config: dict = {}):

53 self._host_name = gethostname()

54 self._lan_ip = gethostbyname(self._host_name)

55 self._clients = []

56 self._selectors = DefaultSelector()

57 self._public_key = None

58 self._public_key_b64 = None

59 self._private_key = None

60 self._address_book = None

61 self._mail_queue = None

62 self._mail_db = None

63 self._wrote_pid_file = False

64 self._client_auth_timeout = None

65 self._client_action_retention_time = None

66 self._ssl_handshake_timeout = dt.timedelta(seconds=SSL_HANDSHAKE_TIMEOUT)

68 self._logger = getLogger('app.server')

69 self._logger.info('init()')

71 self._config = config

73 # TODO: use below

74 if 'contact' in self._config:

75 self._contact = Contact.resolve(self._config['contact'])

76 else:

77 self._contact = Contact()

79 if 'address_book' not in self._config:

80 self._config['address_book'] = {

81 'max_clients': 20,

82 'client_retention_time': 24,

83 }

85 if 'client' not in self._config:

86 self._config['client'] = {

87 'auth_timeout': 2,

88 'action_retention_time': 5,

89 }

90 self._client_auth_timeout = dt.timedelta(seconds=self._config['client']['auth_timeout'])

91 self._client_action_retention_time = dt.timedelta(minutes=self._config['client']['action_retention_time'])

93 if 'data_dir' in self._config:

94 self._pid_file_path = path.join(self._config['data_dir'], 'server.pid')

95 self._write_pid_file()

97 if 'public_key_file' not in self._config:

98 self._config['public_key_file'] = path.join(self._config['data_dir'], 'public_key.pem')

99 if 'private_key_file' not in self._config:

100 self._config['private_key_file'] = path.join(self._config['data_dir'], 'private_key.pem')

101

102 self._certificate_file = path.join(self._config['data_dir'], 'certificate.pem')

103

104 if 'keys_dir' not in self._config:

105 self._config['keys_dir'] = path.join(self._config['data_dir'], 'keys')

106 if not path.isdir(self._config['keys_dir']):

107 mkdir(self._config['keys_dir'])

108

109 address_book_path = path.join(self._config['data_dir'], 'address_book.json')

110 self._address_book = AddressBook(address_book_path, self._config)

111 self._address_book.load()

112

113 bootstrap_path = path.join(self._config['data_dir'], 'bootstrap.json')

114 if path.isfile(bootstrap_path):

115 self._address_book.add_bootstrap(bootstrap_path)

116

117 mail_queue_path = path.join(self._config['data_dir'], 'mail_queue.json')

118 self._mail_queue = MailQueue(mail_queue_path, self._config)

119 self._mail_queue.load()

120

121 mail_db_path = path.join(self._config['data_dir'], 'mail_db.json')

122 self._mail_db = MailDatabase(mail_db_path)

123 self._mail_db.load()

124

125 if 'challenge' not in self._config:

126 self._config['challenge'] = {'min': 15, 'max': 20}

127

128 if 'id' in self._config:

129 self._local_node = Node.parse(self._config['id'])

130

131 if isinstance(self._config['discovery'], bool):

132 self._config['discovery'] = {

133 'enabled': self._config['discovery'],

134 'port': 26000,

135 }

136

137 if 'bootstrap' not in self._config:

138 self._config['bootstrap'] = 'default'

139

140 def __del__(self):

141 self._logger.info('__del__()')

142 self._selectors.close()

143

144 if self._address_book:

145 self._address_book.save()

146

147 if self._mail_queue:

148 self._mail_queue.save()

149

150 if self._mail_db:

151 self._mail_db.save()

152

153 self._remove_pid_file()

154

155 self._logger.info('__del__() end')

156

157 def _write_pid_file(self):

158 if path.isfile(self._pid_file_path):

159 self._logger.error('Another instance of FluxChat is already running.')

160 self._logger.error('If this is not the case, delete the file: %s', self._pid_file_path)

161 exit(1)

162

163 with open(self._pid_file_path, 'w') as fh:

164 fh.write(str(getpid()))

165 self._wrote_pid_file = True

166

167 def _remove_pid_file(self):

168 self._logger.info('_remove_pid_file()')

169 if not self._wrote_pid_file:

170 return

171 if path.isfile(self._pid_file_path):

172 remove(self._pid_file_path)

173

174 def start(self):

175 self._logger.info('start')

176

177 self._logger.info('password_key_derivation')

178 self._pkd = password_key_derivation(getenv('FLUXCHAT_KEY_PASSWORD', 'password').encode()).encode()

179

180 self._load_public_key_from_pem_file()

181 self._load_private_key_from_pem_file()

182

183 self._main_server_ssl = SSLContext(PROTOCOL_TLS_SERVER)

184 self._main_server_ssl.minimum_version = SSL_MINIMUM_VERSION

185 self._main_server_ssl.load_cert_chain(certfile=self._certificate_file, keyfile=self._config['private_key_file'], password=self._pkd)

186

187 try:

188 self._logger.debug('create server %s:%s', self._config['address'], self._config['port'])

189 # IPv4

190 self._main_server_socket = create_server((self._config['address'], self._config['port']), family=AF_INET, reuse_port=True)

191 except OSError as e:

192 self._logger.error('OSError: %s', e)

193 raise e

194 except Exception as e:

195 self._logger.error('Exception: %s', e)

196 raise e

197

198 self._logger.debug('listen')

199 self._main_server_socket.listen()

200 self._main_server_socket.setblocking(False)

201 self._selectors.register(self._main_server_socket, EVENT_READ, data={'type': 'main_server'})

202

203 if 'discovery' in self._config and self._config['discovery']['enabled']:

204 self._logger.debug('discovery')

205

206 # IPv4

207 self._discovery_socket = Socket(AF_INET, SOCK_DGRAM) # UDP

208 self._discovery_socket.setsockopt(SOL_SOCKET, SO_BROADCAST, 1)

209 self._discovery_socket.setsockopt(SOL_SOCKET, SO_REUSEADDR, 1)

210

211 try:

212 self._discovery_socket.bind(('0.0.0.0', self._config['discovery']['port']))

213 except OSError as e:

214 self._logger.error('OSError: %s', e)

215 raise e

216

217 self._discovery_socket.setblocking(False)

218

219 if self.has_contact():

220 self._logger.debug('send broadcast')

221 # TODO for production: set port to self._config['discovery']['port'] instead of hard-coded 26000

222 res = self._discovery_socket.sendto(self.get_contact().encode(), ('<broadcast>', 26000))

223 self._logger.debug('res %s', res)

224

225 self._selectors.register(self._discovery_socket, EVENT_READ, data={'type': 'discovery'})

226

227 if 'ipc' in self._config and self._config['ipc']['enabled']:

228 ipc_addr = (self._config['ipc']['address'], self._config['ipc']['port'])

229 self._logger.debug('ipc %s', ipc_addr)

230

231 # IPv4

232 self._ipc_server_socket = Socket(AF_INET, SOCK_STREAM)

233 self._ipc_server_socket.setsockopt(SOL_SOCKET, SO_REUSEADDR, 1)

234 self._ipc_server_socket.bind(ipc_addr)

235 self._ipc_server_socket.listen()

236 self._ipc_server_socket.setblocking(False)

237

238 self._selectors.register(self._ipc_server_socket, EVENT_READ, data={'type': 'ipc_server'})

239

240 def _load_private_key_from_pem_file(self) -> None:

241 self._logger.debug('load private key from pem file')

242

243 if not path.isfile(self._config['private_key_file']):

244 raise Exception('private key file not found: {}'.format(self._config['private_key_file']))

245

246 _pkd = password_key_derivation(getenv('FLUXCHAT_KEY_PASSWORD', 'password').encode()).encode()

247

248 with open(self._config['private_key_file'], 'rb') as f:

249 self._private_key = serialization.load_pem_private_key(f.read(), password=_pkd)

250

251 def _load_public_key_from_pem_file(self) -> None:

252 self._logger.debug('load public key from pem file')

253

254 if not path.isfile(self._config['public_key_file']):

255 raise Exception('public key file not found: {}'.format(self._config['public_key_file']))

256

257 with open(self._config['public_key_file'], 'rb') as f:

258 self._public_key = serialization.load_pem_public_key(f.read())

259

260 # DER is binary representation of public key.

261 public_bin = self._public_key.public_bytes(

262 encoding=serialization.Encoding.DER,

263 format=serialization.PublicFormat.SubjectPublicKeyInfo

264 )

265

266 self._public_key_b64 = b64encode(public_bin).decode()

267

268 # TODO: remove, replace with Contact class

269 def has_contact(self) -> bool:

270 if 'contact' in self._config:

271 if self._config['contact'] == 'disabled' or self._config['contact'] == 'private':

272 return False

273 elif bool(self._config['contact']) == False:

274 return False

275

276 return True

277

278 return False

279

280 # TODO: remove, replace with Contact class

281 def get_contact(self) -> str:

282 if self.has_contact():

283 items = self._config['contact'].split(':')

284 item_len = len(items)

285

286 if item_len == 1:

287 return '{}:{}'.format(items[0], self._config['port'])

288

289 return self._config['contact']

290

291 return 'N/A'

292

293 def _client_is_connected(self, client: Client) -> bool:

294 # self._logger.debug('_client_is_connected()')

295

296 def ffunc(_client):

297 return _client.uuid == client.uuid or _client.id == client.id or _client.address == client.address and _client.port == client.port

298 clients = list(filter(ffunc, self._clients))

299

300 return len(clients) > 0

301

302 def _accept_main_server(self, server_sock: Socket):

303 self._logger.debug('_accept_main_server()')

304

305 client_sock, addr = server_sock.accept()

306 client_sock.setblocking(False)

307

308 client_ssl = self._main_server_ssl.wrap_socket(client_sock, server_side=True, do_handshake_on_connect=False)

309

310 try:

311 self._ssl_handshake(client_ssl)

312 except SslHandshakeError as e:

313 self._logger.error('ssl handshake error: %s', e)

314 return

315

316 self._logger.debug('client_sock: %s', client_sock)

317 self._logger.debug('client_ssl: %s', client_ssl)

318 self._logger.debug('accepted: %s', addr)

319

320 client = Client()

321 client.sock = client_ssl

322 client.conn_mode = 1

323 client.dir_mode = 'i'

324 client.debug_add = 'accept'

325

326 self._selectors.register(client_ssl, EVENT_READ, data={

327 'type': 'main_client',

328 'client': client,

329 })

330

331 self._clients.append(client)

332

333 self._logger.debug('_accept_main_server() client: %s', client)

334

335 def _read_discovery(self, server_sock: Socket):

336 self._logger.debug('_read_discovery()')

337

338 data, addr = server_sock.recvfrom(1024)

339 c_contact_raw = data.decode()

340

341 self._logger.debug('data: %s', data)

342 self._logger.debug('addr: %s', addr)

343

344 if addr[0] == self._lan_ip and addr[1] == self._config['discovery']['port']:

345 self._logger.debug('skip self')

346 return

347

348 c_contact = Contact.resolve(c_contact_raw, addr[0])

349

350 if not c_contact.is_valid:

351 return

352

353 client = self._address_book.get_client_by_addr_port(c_contact.addr, c_contact.port)

354 if client is None:

355 client = self._address_book.add_client(addr=c_contact.addr, port=c_contact.port)

356 client.debug_add = 'discovery, contact: {}'.format(c_contact_raw)

357 else:

358 self._logger.debug('client: %s', client)

359

360 self._logger.debug('read_discovery client: %s', client)

361

362 self._client_connect(client)

363

364 def _accept_ipc_server(self, server_sock: Socket):

365 self._logger.debug('_accept_ipc_server()')

366

367 client_sock, addr = server_sock.accept()

368 client_sock.setblocking(False)

369

370 self._selectors.register(client_sock, EVENT_READ, data={

371 'type': 'ipc_client',

372 })

373

374 def _client_connect(self, client: Client) -> bool:

375 self._logger.debug('_client_connect(%s)', client)

376

377 # TODO: activate for production

378 # if client.address == self._lan_ip and os.environ.get('ALLOW_SELF_CONNECT') != '1':

379 # self._logger.debug('skip, client.address == self._lan_ip')

380 # return False

381 if client.node == self._local_node:

382 self._logger.debug('skip, client.node == self._local_node')

383 return False

384 if client.address is None or client.port is None:

385 self._logger.debug('skip, client.address is None or client.port is None')

386 return False

387

388 client.conn_mode = 1

389 client.dir_mode = 'o'

390 client.refresh_used_at()

391

392 client_ssl = SSLContext(PROTOCOL_TLS_CLIENT)

393 client_ssl.minimum_version = SSL_MINIMUM_VERSION

394 client_ssl.check_hostname = False

395 client_ssl.verify_mode = CERT_NONE

396

397 # IPv4

398 client_sock = Socket(AF_INET, SOCK_STREAM)

399 client_sock.settimeout(2)

400 try:

401 self._logger.debug('client sock connect to %s:%s', client.address, client.port)

402 client_sock.connect((client.address, client.port))

403 self._logger.debug('client sock connect done')

404 except ConnectionRefusedError as e:

405 self._logger.error('ConnectionRefusedError: %s', e)

406 return False

407 except TimeoutError as e:

408 self._logger.error('TimeoutError: %s', e)

409 return False

410 except SocketTimeout as e:

411 self._logger.error('SocketTimeout: %s', e)

412 return False

413 except SocketGetaddrinfo as e:

414 self._logger.error('SocketGetaddrinfo: %s', e)

415 return False

416 except OSError as e:

417 self._logger.error('OSError: %s', e)

418 return False

419

420 client_sock.settimeout(None)

421 client_sock.setblocking(False)

422

423 client_ssl = client_ssl.wrap_socket(client_sock, do_handshake_on_connect=False)

424 # client.sock = client_sock

425 client.sock = client_ssl

426

427 self._selectors.register(client_ssl, EVENT_READ, data={

428 'type': 'main_client',

429 'client': client,

430 })

431

432 self._clients.append(client)

433

434 try:

435 self._ssl_handshake(client_ssl)

436 except SslHandshakeError as e:

437 self._logger.error('ssl handshake error: %s', e)

438 return False

439

440 self._logger.debug('_client_connect done')

441 return True

442

443 def _client_commands(self, sock: Socket, client: Client, commands: RawCommandsType):

444 self._logger.debug('_client_commands(%s)', client)

445

446 for group_i, command_i, payload in commands:

447 #group_i, command_i, payload = raw_command

448 payload_len = len(payload)

449

450 self._logger.debug('group: %d, command %d', group_i, command_i)

451 self._logger.debug('payload: %d %s', payload_len, payload)

452

453 if group_i >= 2 and client.auth != 15:

454 self._logger.debug('not authenticated: %s', client.auth)

455 self._logger.debug('conn mode 0')

456 client.conn_mode = 0

457 client.conn_msg = 'not authenticated'

458 continue

459

460 if group_i == 0: # Basic

461 if command_i == 0:

462 self._logger.info('OK command')

463

464 elif group_i == 1: # Connection, Authentication, etc

465 if command_i == 1:

466 self._logger.info('CHALLENGE command')

467

468 if client.auth & 2 != 0:

469 self._logger.debug('skip, already got CHALLENGE')

470 continue

471

472 client.auth |= 2

473

474 client.challenge.min = int.from_bytes(payload[0], 'little')

475 client.challenge.max = int.from_bytes(payload[1], 'little')

476 client.challenge.data = str(payload[2].decode())

477

478 self._logger.debug('challenge: %s', client.challenge)

479

480 c_data_len = len(client.challenge.data)

481 if c_data_len > 36:

482 self._logger.warning('skip, challenge data too long: %d > 36', c_data_len)

483 self._logger.debug('conn mode 0')

484 client.conn_mode = 0

485 client.conn_msg = 'challenge data too long'

486 continue

487

488 if client.challenge.min > self._config['challenge']['max']:

489 self._logger.warning('skip, challenge min is too big: %d > %d', client.challenge.min, self._config['challenge']['max'])

490 self._logger.debug('conn mode 0')

491 client.conn_mode = 0

492 client.conn_msg = 'challenge min is too big: %d > %d'.format(client.challenge.min, self._config['challenge']['max'])

493 continue

494

495 cash = Cash(client.challenge.data, client.challenge.min)

496 self._logger.debug('mine')

497 cash.mine()

498 self._logger.debug('mine done')

499

500 client.challenge.proof = cash.proof

501 client.challenge.nonce = cash.nonce

502

503 self._logger.debug('challenge: %s', client.challenge)

504 self._logger.debug('cash.min: %s', client.challenge.min)

505 self._logger.debug('cash.max: %s', client.challenge.max)

506 self._logger.debug('cash.data: %s', client.challenge.data)

507 self._logger.debug('cash.proof: %s', cash.proof)

508 self._logger.debug('cash.nonce: %s', cash.nonce)

509

510 elif command_i == 2:

511 self._logger.info('ID command')

512

513 if client.auth & 2 == 0:

514 self._logger.warning('skip, client has first to send CHALLENGE')

515 continue

516

517 if client.auth & 8 != 0:

518 self._logger.debug('skip, already authenticated')

519 continue

520

521 c_version = int.from_bytes(payload[0], 'little')

522 c_id = payload[1].decode()

523 c_contact_s = payload[2].decode()

524 c_cc_proof = payload[3].decode()

525 c_cc_nonce = int.from_bytes(payload[4], 'little')

526

527 self._logger.debug('c_version: %s', c_version)

528 self._logger.debug('c_id: %s', c_id)

529 self._logger.debug('c_contact_s: %s', c_contact_s)

530 self._logger.debug('c_cc_proof: %s', c_cc_proof)

531 self._logger.debug('c_cc_nonce: %s', c_cc_nonce)

532

533 # Local

534 if self._local_node == c_id:

535 self._logger.debug('skip, ID is local node')

536 self._logger.debug('conn mode 0')

537 client.conn_mode = 0

538 client.conn_msg = 'ID is local node'

539 continue

540

541 # Version

542 if c_version != VERSION:

543 self._logger.warning('skip, version mismatch: %d != %d', c_version, VERSION)

544 self._logger.debug('conn mode 0')

545 client.conn_mode = 0

546 client.conn_msg = 'version mismatch'

547 continue

548

549 # Challenge

550 if not client.cash.verify(c_cc_proof, c_cc_nonce):

551 self._logger.warning('skip, challenge not verified')

552 self._logger.debug('conn mode 0')

553 client.conn_mode = 0

554 client.conn_msg = 'challenge not verified'

555 continue

556 self._logger.debug('cash verified')

557

558 # Contact info

559 addr = sock.getpeername()

560 c_contact = Contact.resolve(c_contact_s, addr[0])

561 c_contact_addr = c_contact.addr

562 c_contact_port = c_contact.port

563 c_has_contact_info = c_contact.is_valid

564

565 c_switch = False

566 if client.dir_mode == 'i':

567 # Client is incoming

568 self._logger.debug('client is incoming')

569

570 if c_has_contact_info:

571 # Client sent contact info

572 _client = self._address_book.get_client_by_id(c_id)

573 if _client is None:

574 self._logger.debug('client not found by ID (A)')

575

576 _client = self._address_book.get_client_by_addr_port(c_contact_addr, c_contact_port)

577 if _client is None:

578 self._logger.debug('client not found by Addr:Port (B)')

579

580 _client = self._address_book.add_client(c_id, c_contact_addr, c_contact_port)

581 _client.dir_mode = client.dir_mode

582 _client.debug_add = 'id command, incoming, contact infos, not found by id, not found by addr:port, original: ' + client.debug_add

583 else:

584 self._logger.debug('client found B: %s', _client)

585 else:

586 self._logger.debug('client found A: %s', _client)

587

588 _client.address = c_contact_addr

589 _client.port = c_contact_port

590 else:

591 # Client sent no contact info

592 _client = self._address_book.get_client_by_id(c_id)

593 if _client is None:

594 self._logger.debug('client not found C')

595

596 _client = self._address_book.add_client(c_id)

597 _client.dir_mode = client.dir_mode

598 _client.debug_add = 'id command, incoming, no contact infos, not found by id, original: ' + client.debug_add

599 else:

600 self._logger.debug('client found C: {}'.format(_client))

601

602 c_switch = True

603

604 elif client.dir_mode == 'o':

605 # Client is outgoing

606 self._logger.debug('client is outgoing')

607

608 _client = client

609

610 if c_has_contact_info:

611 self._logger.debug('client has contact infos')

612 _client.address = c_contact_addr

613 _client.port = c_contact_port

614 else:

615 self._logger.debug('client has NO contact infos')

616

617 if _client.id is None:

618 _client.id = c_id

619

620 self._logger.debug('Client A: %s', client)

621 self._logger.debug('Client B: %s', _client)

622

623 _client.refresh_seen_at()

624 _client.refresh_used_at()

625 _client.inc_meetings()

626

627 _client.sock = sock

628 _client.conn_mode = client.conn_mode

629 _client.auth = client.auth | 8

630 _client.actions = client.actions

631 _client.challenge = client.challenge

632

633 # Update Address Book because also an existing client can be updated

634 self._address_book.changed()

635

636 if c_switch and _client != client:

637 self._logger.debug('switch client')

638 self._clients.remove(client)

639 self._clients.append(_client)

640

641 self._selectors.unregister(sock)

642 self._selectors.register(_client.sock, EVENT_READ, data={

643 'type': 'main_client',

644 'client': _client,

645 })

646

647 self._client_send_ok(_client.sock)

648

649 self._logger.debug('Client Z: %s', _client)

650

651 elif command_i == 3:

652 self._logger.info('PING command')

653 self._client_send_pong(sock)

654

655 elif command_i == 4:

656 self._logger.info('PONG command')

657

658 elif group_i == 2: # Overlay, Address Book, Routing, etc

659 if command_i == 1:

660 self._logger.info('GET_NEAREST_TO command')

661

662 try:

663 node = Node(payload[0].decode())

664 except:

665 self._logger.warning('skip, invalid node')

666 continue

667

668 client_ids = []

669 clients = self._address_book.get_nearest_to(node, with_contact_infos=True)

670 for _client in clients:

671 self._logger.debug('client: %s %s', _client, _client.distance(node))

672 if _client.id != self._local_node.id and _client.id != node.id:

673 contact_infos = [_client.id, _client.address, str(_client.port)]

674 self._logger.debug('contact infos: %s', contact_infos)

675 client_ids.append(':'.join(contact_infos))

676

677 self._client_send_get_nearest_response(sock, client_ids)

678

679 elif command_i == 2:

680 self._logger.info('GET_NEAREST_TO RESPONSE command')

681

682 action = client.resolve_action('nearest_response')

683 if action is None:

684 self._logger.warning('skip, not requested')

685 continue

686

687 self._logger.debug('action: %s', action)

688

689 nearest_client = None

690 distance = Distance()

691 for c_contact in payload:

692 self._logger.debug('client contact A: %s', c_contact)

693

694 c_id, c_contact_raw = c_contact.decode().split(':', 1)

695 self._logger.debug('client contact B: %s %s', c_id, c_contact_raw)

696

697 c_contact = Contact.resolve(c_contact_raw)

698 self._logger.debug('client contact C: %s %s %s', c_contact.addr, c_contact.port, c_contact.is_valid)

699

700 if c_id == self._local_node.id:

701 continue

702

703 _client = self._address_book.get_client_by_id(c_id)

704 if _client is None:

705 self._logger.debug('client not found')

706 _client = self._address_book.add_client(c_id, c_contact.addr, c_contact.port)

707 _client.debug_add = 'nearest response, not found by id'

708

709 _c_distance = _client.distance(self._local_node)

710 if _c_distance < distance:

711 # distance = _client.distance(self._local_node)

712 distance = _c_distance

713 self._logger.debug('new distance: %s', distance)

714

715 nearest_client = _client

716 else:

717 self._logger.debug('client found: %s', _client)

718

719 if nearest_client is not None:

720 self._logger.debug('nearest client: %s', nearest_client)

721

722 bootstrap_count = action.data - 1

723 self._logger.debug('bootstrap count: %d', bootstrap_count)

724

725 if bootstrap_count > 0 and not self._client_is_connected(nearest_client):

726 self._client_connect(nearest_client)

727

728 nearest_client.add_action(Action('bootstrap', data=bootstrap_count))

729

730 elif command_i == 3:

731 self._logger.info('REQUEST PUBLIC KEY FOR NODE command')

732

733 is_relay = False

734 fwd_clients = []

735 node_id = payload[0].decode()

736 self._logger.debug('node id: %s', node_id)

737

738 try:

739 target = Node.parse(node_id)

740 except:

741 self._logger.debug('skip, invalid node')

742 continue

743

744 if target == self._local_node:

745 self._logger.debug('local node')

746 self._client_response_public_key_for_node(sock, target.id, self._public_key_b64)

747 else:

748 self._logger.debug('not local node')

749

750 _client = self._address_book.get_client_by_id(target.id)

751 if _client is None:

752 self._logger.debug('client not found')

753

754 is_relay = True

755 fwd_clients = self._address_book.get_nearest_to(target, with_contact_infos=True)

756 else:

757 self._logger.debug('client found: %s', _client)

758

759 if _client.has_public_key():

760 self._logger.debug('client has public key')

761

762 self._client_response_public_key_for_node(sock, target.id, _client.get_base64_public_key())

763 else:

764 self._logger.debug('client does not have public key')

765

766 self._logger.debug('relay')

767 is_relay = True

768 fwd_clients = [_client]

769

770 if is_relay:

771 for _client in fwd_clients:

772 if client == _client:

773 self._logger.debug('client is self')

774 continue

775

776 self._logger.debug('client: %s', _client)

777

778 if _client.has_action('request_public_key_for_node', target.id):

779 self._logger.debug('client already has action request_public_key_for_node/%s', target.id)

780 else:

781 self._logger.debug('create action request_public_key_for_node/%s', target.id)

782

783 action = self._create_action_request_public_key_for_node(target, 'r')

784

785 action.func = lambda _arg_client: self._client_response_public_key_for_node(sock, target.id, _arg_client.get_base64_public_key())

786

787 _client.add_action(action)

788

789 elif command_i == 4:

790 self._logger.info('RESPONSE PUBLIC KEY FOR NODE command')

791

792 node_id = payload[0].decode()

793 public_key_raw = payload[1].decode()

794 self._logger.debug('node id: %s', node_id)

795 self._logger.debug('public key raw: %s', public_key_raw)

796

797 try:

798 node = Node.parse(node_id)

799 self._logger.debug('node: %s', node)

800 except:

801 self._logger.debug('skip, invalid node')

802 continue

803

804 action = client.resolve_action('request_public_key_for_node', node.id, force_remove=True)

805 if action is None:

806 self._logger.warning('skip, not requested')

807 continue

808

809 if node == self._local_node:

810 self._logger.warning('skip, local node')

811 continue

812

813 self._logger.debug('action: %s', action)

814

815 _client = self._address_book.get_client_by_id(node.id)

816 if _client is None:

817 self._logger.debug('client not found')

818

819 _client = Client()

820 _client.debug_add = 'public key response'

821 _client.set_id(node.id)

822 _client.load_public_key_from_pem(public_key_raw)

823

824 if _client.verify_public_key():

825 self._logger.debug('public key verified')

826

827 self._address_book.append_client(_client)

828 self._logger.debug('client added: %s', _client)

829 else:

830 self._logger.debug('public key not verified')

831 _client = None

832 else:

833 self._logger.debug('client found: %s', _client)

834

835 if _client.has_public_key():

836 self._logger.debug('client has public key')

837 else:

838 _client.load_public_key_from_pem(public_key_raw)

839 if _client.verify_public_key():

840 self._logger.debug('public key verified')

841 self._address_book.changed()

842 else:

843 self._logger.debug('public key not verified')

844 _client.reset_public_key()

845

846 if _client is not None and _client.has_public_key():

847 self._logger.debug('client is set and has public key')

848 self._logger.debug('client: %s', _client)

849

850 if action.func is not None:

851 self._logger.debug('action has func')

852 self._logger.debug('call func')

853 action.func(_client)

854

855 elif group_i == 3: # Mail

856 if command_i == 1:

857 self._logger.debug('SEND MAIL command')

858

859 mail_uuid, mail_target, mail_data = payload

860

861 self._logger.debug('mail uuid: %s', mail_uuid)

862 if not is_valid_uuid(mail_uuid):

863 self._logger.debug('invalid mail uuid')

864 continue

865

866 if self._mail_db.has_mail(mail_uuid):

867 self._logger.debug('DB, mail already exists')

868 continue

869

870 if self._mail_queue.has_mail(mail_uuid):

871 self._logger.debug('QUEUE, mail already exists')

872 continue

873

874 try:

875 mail_target = Node.parse(mail_target)

876 self._logger.debug('mail target: %s', mail_target)

877 except:

878 self._logger.debug('invalid mail target')

879 continue

880

881 self._logger.debug('mail data: %s', mail_data)

882

883 mail = Mail(mail_uuid)

884 mail.receiver = mail_target.id

885 mail.target = mail_target

886 mail.body = mail_data

887 mail.is_encrypted = True

888 mail.received_now()

889

890 if mail_target == self._local_node:

891 self._logger.debug('mail target is local node')

892 self._decrypt_mail(mail)

893 self._mail_db.add_mail(mail)

894 else:

895 self._logger.debug('mail target is not local node')

896 mail.forwarded_to.append(client.id)

897 self._mail_queue.add_mail(mail)

898

899 else:

900 self._logger.debug('unknown group %d, command %d', group_i, command_i)

901 self._logger.debug('conn mode 0')

902 client.conn_mode = 0

903 client.conn_msg = 'unknown group %d, command %d' % (group_i, command_i)

904

905 def _client_send_ok(self, sock: Socket):

906 self._logger.debug('_client_send_ok()')

907 self._client_write(sock, 0, 0)

908

909 def _client_send_challenge(self, sock: Socket, challenge: str):

910 self._logger.debug('_client_send_challenge(%s)', challenge)

911

912 self._client_write(sock, 1, 1, [

913 self._config['challenge']['min'],

914 self._config['challenge']['max'],

915 challenge,

916 ])

917

918 def _client_send_id(self, sock: Socket, proof: str, nonce: int):

919 self._logger.debug('_client_send_id(%s, %d)', proof, nonce)

920 data = [

921 VERSION,

922 self._config['id'],

923 self._config['contact'],

924 proof,

925 nonce,

926 ]

927

928 # self._logger.debug('data: %s', data)

929 self._client_write(sock, 1, 2, data)

930

931 def _client_send_ping(self, sock: Socket):

932 self._logger.debug('_client_send_ping()')

933 self._client_write(sock, 1, 3)

934

935 def _client_send_pong(self, sock: Socket):

936 self._logger.debug('_client_send_pong()')

937 self._client_write(sock, 1, 4)

938

939 def _client_send_get_nearest_to(self, sock: Socket, id: str):

940 self._logger.debug('_client_send_get_nearest_to()')

941 self._client_write(sock, 2, 1, [id])

942

943 def _client_send_get_nearest_response(self, sock: Socket, client_ids: list):

944 self._logger.debug('_client_send_get_nearest_response()')

945 self._client_write(sock, 2, 2, client_ids)

946

947 def _client_request_public_key_for_node(self, sock: Socket, id: str):

948 self._logger.debug('_client_request_public_key_for_node(%s)', id)

949 self._client_write(sock, 2, 3, [id])

950

951 def _client_response_public_key_for_node(self, sock: Socket, id: str, public_key: str):

952 self._logger.debug('_client_response_public_key_for_node()')

953 # self._logger.debug('type: %s', type(id))

954 # self._logger.debug('type: %s', type(public_key))

955 self._logger.debug('public key: %s', public_key)

956

957 self._client_write(sock, 2, 4, [id, public_key])

958

959 def _client_send_mail(self, sock: Socket, mail: Mail):

960 self._logger.debug('_client_send_mail()')

961 if not mail.is_encrypted:

962 self._logger.debug('mail not encrypted')

963 return

964

965 self._logger.debug('mail: %s', type(mail.body))

966

967 self._client_write(sock, 3, 1, [

968 mail.uuid,

969 mail.target.id,

970 mail.body,

971 ])

972

973 def _ipc_client_read(self, sock: Socket):

974 self._logger.debug('_ipc_client_read()')

975

976 try:

977 raw = sock.recv(2048)

978 except TimeoutError as e:

979 self._logger.error('IPC TimeoutError: %s', e)

980 return

981 except ConnectionResetError as e:

982 self._logger.error('IPC ConnectionResetError: %s', e)

983 raw = False

984

985 if raw:

986 raw_len = len(raw)

987

988 raw_pos = 0

989 commands = []

990 while raw_pos < raw_len:

991 try:

992 flags_i = raw[raw_pos]

993 raw_pos += 1

994

995 group = raw[raw_pos]

996 raw_pos += 1

997

998 command = raw[raw_pos]

999 raw_pos += 1

1000 except IndexError as e:

1001 self._logger.error('IPC IndexError: %s', e)

1002 self._logger.error('IPC unregister socket')

1003 self._selectors.unregister(sock)

1004 return

1005

1006 lengths_are_4_bytes = flags_i & 1 != 0

1007

1008 try:

1009 # length = unpack('<I', raw[raw_pos:raw_pos + 4])[0]

1010 length = int.from_bytes(raw[raw_pos:raw_pos + 4], 'little')

1011 raw_pos += 4

1012 except StructError as e:

1013 self._logger.error('IPC struct.error: %s', e)

1014 self._logger.error('IPC unregister socket')

1015 self._selectors.unregister(sock)

1016 return

1017

1018 payload_raw = raw[raw_pos:]

1019 payload_items = []

1020

1021 self._logger.debug('IPC group: %d', group)

1022 self._logger.debug('IPC command: %d', command)

1023 self._logger.debug('IPC length: %d %s', length, type(length))

1024

1025 pos = 0

1026 while pos < length:

1027 self._logger.debug('IPC pos: %d', pos)

1028 if lengths_are_4_bytes:

1029 # item_len = unpack('<I', payload_raw[pos:pos + 4])[0]

1030 item_len = int.from_bytes(payload_raw[pos:pos + 4], 'little')

1031 pos += 3

1032 else:

1033 item_len = payload_raw[pos]

1034 pos += 1

1035

1036 self._logger.debug('IPC item len: %d', item_len)

1037

1038 item = payload_raw[pos:pos + item_len]

1039 self._logger.debug('IPC item: %s', item)

1040

1041 payload_items.append(item.decode())

1042 pos += item_len

1043

1044 commands.append([group, command, payload_items])

1045 raw_pos += length + 1

1046

1047 self._ipc_client_commands(sock, commands)

1048 else:

1049 self._logger.debug('no data')

1050

1051 self._logger.debug('IPC unregister socket')

1052 self._selectors.unregister(sock)

1053

1054 def _ipc_client_commands(self, sock: Socket, commands: RawCommandsType):

1055 self._logger.debug('_ipc_client_commands()')

1056 self._logger.debug('commands: %s', commands)

1057

1058 for group_i, command_i, payload in commands:

1059 payload_len = len(payload)

1060

1061 self._logger.debug('group %d, command %d', group_i, command_i)

1062 self._logger.debug('payload_len: %d', payload_len)

1063 self._logger.debug('payload: %s', payload)

1064

1065 if group_i == 0: # Basic

1066 if command_i == 0:

1067 self._logger.info('OK command')

1068

1069 elif group_i == 1:

1070 if command_i == 0:

1071 self._logger.info('SEND MAIL command')

1072

1073 print(f'-> payload: {payload}')

1074

1075 target = payload[0]

1076 body = payload[1]

1077 self._logger.debug('target: %s', target)

1078 self._logger.debug('body: %s', body)

1079

1080 mail = Mail()

1081 mail.set_receiver(target)

1082 mail.body = body

1083 self._mail_queue.add_mail(mail)

1084

1085 self._logger.debug('uuid: %s', mail.uuid)

1086

1087 self._client_send_ok(sock)

1088

1089 elif command_i == 1:

1090 self._logger.info('LIST MAILS command')

1091

1092 flags_i = int.from_bytes(payload[0], 'little')

1093 only_new = flags_i & 1 != 0

1094 self._logger.debug('flags_i: %d', flags_i)

1095 self._logger.debug('only_new: %s', only_new)

1096

1097 mails = list(self._mail_db.get_mails())

1098

1099 if only_new:

1100 mails = list(filter(lambda _mail: _mail[1].is_new, mails))

1101 # mails = dict(filter(lambda _mail: _mail[1].is_new, mails))

1102

1103 # print('mails: %s' % mails)

1104

1105 chunks = []

1106 for n in range(0, len(mails), 5):

1107 encoded_mails = list(map(lambda _mail: _mail[1].ipc_encode(), mails[n:n + 5]))

1108 chunks.append(encoded_mails)

1109

1110 chunks_len = len(chunks)

1111 self._logger.debug('chunks_len: %d', chunks_len)

1112

1113 for n in range(chunks_len):

1114 self._logger.debug('chunk n: %d', n)

1115 self._ipc_client_send_list_mail(sock, chunks_len, n, chunks[n])

1116

1117 elif command_i == 2:

1118 self._logger.info('READ MAIL command')

1119

1120 m_uuid = payload[0].decode()

1121 self._logger.debug('m_uuid: %s', m_uuid)

1122

1123 mail = self._mail_db.get_mail(m_uuid)

1124 if mail is None:

1125 self._logger.error('mail not found')

1126 mail_encoded = None

1127 else:

1128 self._logger.debug('mail: %s', mail)

1129

1130 mail_encoded = mail.ipc_encode()

1131 self._logger.debug('mail_encoded: %s', mail_encoded)

1132

1133 self._ipc_client_send_read_mail(sock, mail_encoded)

1134

1135 elif group_i == 2:

1136 if command_i == 0:

1137 self._logger.debug('SAVE command')

1138 self.save()

1139

1140 if command_i == 1:

1141 self._logger.debug('STOP command')

1142 self._scheduler.shutdown('STOP command')

1143

1144 def _ipc_client_send_list_mail(self, sock: Socket, chunks_len: int, chunk_num: int, mails: list):

1145 self._logger.debug('_ipc_client_send_list_mail()')

1146 self._logger.debug('mails: %s', mails)

1147

1148 self._client_write(sock, 1, 1, [chunks_len, chunk_num] + mails)

1149

1150 def _ipc_client_send_read_mail(self, sock: Socket, mail: str):

1151 self._logger.debug('_ipc_client_send_read_mail()')

1152 self._logger.debug('mail: %s', mail)

1153

1154 if mail is not None:

1155 data = [1, mail]

1156 else:

1157 data = [0]

1158

1159 self._client_write(sock, 1, 2, data)

1160

1161 def handle_sockets(self) -> bool:

1162 # self._logger.debug('handle_sockets()')

1163

1164 data_processed = False

1165

1166 events = self._selectors.select(timeout=0)

1167 for key, mask in events:

1168 self._logger.debug('handle_sockets mask: %d', mask)

1169

1170 if key.data is not None:

1171 if key.data['type'] == 'main_server':

1172 self._accept_main_server(key.fileobj)

1173

1174 elif key.data['type'] == 'main_client':

1175 status = self._client_read(key.fileobj)

1176

1177 if status.disconnect:

1178 self._logger.debug('client disconnect: %s', status.msg)

1179 key.data['client'].conn_mode = 0

1180 key.data['client'].conn_msg = status.msg

1181

1182 self._client_commands(key.fileobj, key.data['client'], status.commands)

1183

1184 elif key.data['type'] == 'discovery':

1185 self._logger.debug('discovery')

1186 self._read_discovery(key.fileobj)

1187

1188 elif key.data['type'] == 'ipc_server':

1189 self._accept_ipc_server(key.fileobj)

1190

1191 elif key.data['type'] == 'ipc_client':

1192 self._ipc_client_read(key.fileobj)

1193

1194 data_processed = True

1195

1196 return data_processed # will be returned to the Scheduler

1197

1198 def contact_address_book(self) -> bool:

1199 self._logger.debug('contact_address_book()')

1200

1201 _clients = list(self._address_book.get_clients().values())

1202 _clients.sort(key=lambda _client: _client.meetings, reverse=True)

1203

1204 # self._logger.debug('clients: %d', len(_clients))

1205

1206 connect_to_clients: list[Client] = []

1207 zero_meetings_clients = []

1208 for client in _clients:

1209 self._logger.debug('contact: %s', client)

1210

1211 if client.meetings > 0:

1212 if not self._client_is_connected(client):

1213 self._logger.debug('client is not connected A')

1214 connect_to_clients.append(client)

1215 else:

1216 zero_meetings_clients.append(client)

1217

1218 zero_meetings_clients.sort(key=lambda _client: _client.distance(self._local_node))

1219 for client in zero_meetings_clients:

1220 self._logger.debug('zero_meetings_client: %s', client)

1221 if not self._client_is_connected(client):

1222 self._logger.debug('client is not connected B')

1223 connect_to_clients.append(client)

1224

1225 is_bootstrapping = self.is_bootstrap_phase()

1226

1227 for client in connect_to_clients:

1228 if is_bootstrapping:

1229 client.add_action(Action('bootstrap', data=2)) # TODO for production: set to 7

1230 self._client_connect(client)

1231

1232 return True

1233

1234 def get_clients(self) -> list[Client]:

1235 return self._clients

1236

1237 def add_client(self, client: Client):

1238 self._clients.append(client)

1239

1240 def handle_clients(self) -> bool:

1241 for client in self._clients:

1242

1243 # Remove clients that are not connected

1244 if client.conn_mode == 0:

1245 self._logger.debug('remove client: %s', client)

1246 self._logger.debug('reason: %s', client.conn_msg)

1247 self._selectors.unregister(client.sock)

1248 client.sock.close()

1249 self._clients.remove(client)

1250

1251 client.reset()

1252

1253 if client.conn_mode == 1:

1254 if client.auth & 1 == 0:

1255 data_org = str(uuid4())

1256 client.cash = Cash(data_org, self._config['challenge']['min'])

1257

1258 self._logger.debug('send CHALLENGE')

1259 self._client_send_challenge(client.sock, data_org)

1260 client.auth |= 1

1261

1262 elif client.auth & 2 != 0 and client.auth & 4 == 0:

1263 self._logger.debug('send ID')

1264 self._client_send_id(client.sock, client.challenge.proof, client.challenge.nonce)

1265 client.auth |= 4

1266

1267 if client.auth == 15:

1268 client.conn_mode = 2

1269

1270 # Auth Timeout

1271 if dt.datetime.now(dt.UTC) - client.used_at >= self._client_auth_timeout:

1272 self._logger.debug('client used_at: %s', client.used_at)

1273 self._logger.debug('client timeout (%s)', self._client_auth_timeout)

1274 client.conn_mode = 0

1275 client.conn_msg = 'timeout'

1276

1277 return True

1278

1279 def ping_clients(self) -> bool:

1280 for client in self._clients:

1281 if client.conn_mode == 2:

1282 self._logger.debug('send PING')

1283 self._client_send_ping(client.sock)

1284

1285 return True

1286

1287 def save(self) -> bool:

1288 self._logger.debug('save()')

1289

1290 self._address_book.save()

1291 self._mail_queue.save()

1292 self._mail_db.save()

1293

1294 return True

1295

1296 def clean_up(self) -> bool:

1297 self._logger.debug('clean_up')

1298

1299 # self._address_book.hard_clean_up(self._local_node.id)

1300 self._address_book.soft_clean_up(self._local_node.id)

1301

1302 self._mail_queue.clean_up()

1303

1304 return True

1305

1306 def debug_clients(self) -> bool:

1307 self._logger.debug('debug_clients() -> %d', len(self._clients))

1308

1309 for client in self._clients:

1310 self._logger.debug('debug %s', client)

1311

1312 return True

1313

1314 def client_actions(self) -> bool:

1315 self._logger.debug('client_actions() -> %d', len(self._clients))

1316

1317 had_actions = False

1318

1319 for client in self._clients:

1320 self._logger.debug('client %s', client)

1321

1322 for action in client.get_actions(soft_reset=True):

1323 self._logger.debug('action %s', action)

1324

1325 if action.id == 'bootstrap':

1326 self._client_send_get_nearest_to(client.sock, self._local_node.id)

1327 client.add_action(Action('nearest_response', data=action.data))

1328

1329 elif action.id == 'request_public_key_for_node':

1330 self._logger.debug('request_public_key_for_node (try: %d)', action.data['try'])

1331

1332 self._client_request_public_key_for_node(client.sock, action.data['target'].id)

1333 action.data['try'] += 1

1334

1335 elif action.id == 'mail':

1336 mail = action.data

1337 self._logger.debug('mail %s', mail)

1338

1339 self._client_send_mail(client.sock, mail)

1340

1341 mail.forwarded_to.append(client.id)

1342 mail.is_delivered = client.id == mail.target

1343

1344 self._mail_queue.changed()

1345

1346 elif action.id == 'test':

1347 had_actions = True

1348

1349 if action.valid_until is not None and dt.datetime.now(dt.UTC) >= action.valid_until:

1350 self._logger.debug('action is invalid: %s', action)

1351 client.remove_action(action)

1352

1353 return had_actions

1354

1355 def _create_action_request_public_key_for_node(self, target: Node, mode: str) -> Action:

1356 self._logger.debug('_create_action_request_public_key_for_node(%s, %s)', target, mode)

1357

1358 action_data = {

1359 'target': target,

1360 'mode': mode, # (o)riginal sender, (r)elay

1361 # 'step': 0, # 0 = request created, 1 = send request to client

1362 'try': 0, # 0 = first try, 1 = second try, etc

1363 }

1364 action = Action('request_public_key_for_node', target.id, data=action_data)

1365 action.valid_until = dt.datetime.now(dt.UTC) + self._client_action_retention_time

1366 action.is_strong = True

1367

1368 return action

1369

1370 def is_bootstrap_phase(self) -> bool:

1371 if self._config['bootstrap'] == 'default':

1372 clients_len = self._address_book.get_clients_len()

1373 bootstrap_clients_len = self._address_book.get_bootstrap_clients_len()

1374 return clients_len <= bootstrap_clients_len

1375

1376 return bool(self._config['bootstrap'])

1377

1378 def handle_mail_queue(self) -> bool:

1379 self._logger.debug('handle_mail_queue()')

1380

1381 for mail_uuid, mail in self._mail_queue.get_mails().items():

1382 self._logger.debug('mail %s', mail)

1383

1384 if mail.is_delivered:

1385 self._logger.debug('mail is delivered')

1386 continue

1387

1388 if mail.target is None:

1389 self._logger.debug('mail has no target')

1390 continue

1391

1392 if mail.target == self._local_node.id:

1393 self._logger.debug('mail is for me')

1394 continue

1395

1396 clients = self._address_book.get_nearest_to(mail.target, with_contact_infos=True)

1397 self._logger.debug('clients %s', clients)

1398

1399 for client in clients:

1400 self._logger.debug('client for mail: %s', client)

1401 if self._client_is_connected(client):

1402 # self._logger.debug('client is connected')

1403 pass

1404 else:

1405 self._logger.debug('client is not connected C')

1406 self._client_connect(client)

1407

1408 if mail.is_encrypted:

1409 self._logger.debug('mail is encrypted')

1410

1411 for client in clients:

1412 self._logger.debug('client %s', client)

1413 self._logger.debug('forwarded_to %s', mail.forwarded_to)

1414

1415 if not self._client_is_connected(client):

1416 self._logger.debug('client is not connected D')

1417 continue

1418

1419 if client.id in mail.forwarded_to:

1420 self._logger.debug('client already received mail')

1421 continue

1422

1423 if client.has_action('mail', mail.uuid):

1424 self._logger.debug('client already has action')

1425 continue

1426

1427 self._logger.debug('add action for mail')

1428 action = Action('mail', mail.uuid, data=mail)

1429 action.valid_until = dt.datetime.now(dt.UTC) + self._client_action_retention_time

1430 client.add_action(action)

1431 else:

1432 self._logger.debug('mail is not encrypted yet')

1433

1434 client = self._address_book.get_client_by_id(mail.target.id)

1435 if client is None or not client.has_public_key():

1436 self._logger.debug('client is set and has no public key')

1437 for client in clients:

1438

1439 if client.has_action('request_public_key_for_node', mail.target.id):

1440 self._logger.debug('client already has action request_public_key_for_node/%s', mail.target.id)

1441 else:

1442 self._logger.debug('create action request_public_key_for_node from client: %s', client)

1443

1444 action = self._create_action_request_public_key_for_node(mail.target, 'o')

1445

1446 action.func = lambda _client: self._encrypt_mail(mail, _client)

1447

1448 client.add_action(action)

1449 else:

1450 self._encrypt_mail(mail, client)

1451

1452 return True

1453

1454 def handle_mail_db(self) -> bool:

1455 # self._logger.debug('handle_mail_db()')

1456

1457 for mail_uuid, mail in self._mail_db.get_mails():

1458 # self._logger.debug('mail %s', mail)

1459

1460 clients = self._address_book.get_nearest_to(mail.origin, with_contact_infos=True)

1461 # self._logger.debug('clients %s', clients)

1462

1463 for client in clients:

1464 # self._logger.debug('client for mail: %s', client)

1465 if self._client_is_connected(client):

1466 pass

1467 # self._logger.debug('client is connected')

1468 else:

1469 # self._logger.debug('client is not connected C')

1470 self._client_connect(client)

1471

1472 if mail.verified == 'n':

1473 self._logger.debug('mail is not verified')

1474

1475 _client = self._address_book.get_client_by_id(mail.origin.id)

1476

1477 request_public_key_for_node_action = False

1478 if _client is None:

1479 self._logger.debug('client not found by id: %s', mail.origin.id)

1480 request_public_key_for_node_action = True

1481 else:

1482 self._logger.debug('client found by id: %s', mail.origin.id)

1483 if _client.has_public_key():

1484 self._logger.debug('client has public key')

1485 self._verify_mail(mail, _client)

1486 else:

1487 self._logger.debug('client has no public key')

1488 request_public_key_for_node_action = True

1489

1490 if request_public_key_for_node_action:

1491 for client in clients:

1492 if client.has_action('request_public_key_for_node', mail.origin.id):

1493 self._logger.debug('client already has action request_public_key_for_node/%s', mail.origin.id)

1494 else:

1495 self._logger.debug('create action request_public_key_for_node from client: %s', client)

1496 action = self._create_action_request_public_key_for_node(mail.origin, 'o')

1497 action.func = lambda client: self._verify_mail(mail, client)

1498 client.add_action(action)

1499

1500 # Use public key to encrypt symmetric key.

1501 # Use symmetric key to encrypt mail body.

1502 def _encrypt_mail(self, mail: Mail, client: Client):

1503 self._logger.debug('_encrypt_mail() -> {}'.format(mail.is_encrypted))

1504 self._logger.debug('mail %s', mail)

1505 self._logger.debug('client %s', client)

1506

1507 if mail.is_encrypted:

1508 self._logger.debug('mail is already encrypted')

1509 return

1510

1511 # Raw Body

1512 raw_body = b64decode(mail.body)

1513 raw_body_len = len(raw_body).to_bytes(2, 'little')

1514 self._logger.debug('raw body "%s"', raw_body)

1515 self._logger.debug('raw body len %s', raw_body_len)

1516

1517 # Symmetric Key

1518 sym_key = Fernet.generate_key()

1519 self._logger.debug('sym_key: %s', sym_key)

1520 self._logger.debug('sym_key hex: %s', sym_key.hex())

1521

1522 # Signature Data

1523 hasher = hashes.Hash(hashes.SHA256())

1524 hasher.update(sym_key)

1525 hasher.update(raw_body)

1526 sign_hash = hasher.finalize()

1527

1528 sign_hash_b64 = b64encode(sign_hash).decode()

1529 self._logger.debug('sign_hash: %s', sign_hash_b64)

1530

1531 # Signature

1532 signature = self._private_key.sign(

1533 sign_hash,

1534 padding.PSS(

1535 mgf=padding.MGF1(hashes.SHA256()),

1536 salt_length=padding.PSS.MAX_LENGTH

1537 ),

1538 hashes.SHA256()

1539 )

1540 sig_len = len(signature).to_bytes(2, 'little')

1541 self._logger.debug('sign len: %d %s', len(signature), sig_len)

1542 self._logger.debug('signature: %s', signature)

1543

1544 # Symmetric Data

1545 sym_items = {

1546 0x00: signature,

1547 0x01: raw_body,

1548 }

1549 sym_data = binary_encode(sym_items, 2)

1550

1551 # Symmetric Key encrypted

1552 f = Fernet(sym_key)

1553 token = f.encrypt(sym_data)

1554 token_len = len(token).to_bytes(4, 'little')

1555 self._logger.debug('token_len "%s"', token_len)

1556 self._logger.debug('token "%s"', token)

1557

1558 # Encrypted Symmetric Key using Public Key

1559 enc_sym_key = client.encrypt(sym_key)

1560 enc_sym_key_len = len(enc_sym_key).to_bytes(2, 'little')

1561 self._logger.debug('enc_sym_key_len "%s"', enc_sym_key_len)

1562 self._logger.debug('enc_sym_key "%s"', enc_sym_key)

1563

1564 # Public Data

1565 pub_items = {

1566 0x00: enc_sym_key,

1567 0x01: token,

1568 }

1569 # 4 bytes for length = 4 * 8 bits = 32 bits = 2^32 = 4.294.967.296 bytes

1570 pub_data = binary_encode(pub_items, 4)

1571

1572 encoded = b64encode(pub_data).decode()

1573 self._logger.debug('pub data b64 "%s"', encoded)

1574

1575 mail.body = encoded

1576 mail.is_encrypted = True

1577

1578 self._mail_queue.changed()

1579

1580 client.refresh_used_at()

1581 self._address_book.changed()

1582

1583 def _decrypt_mail(self, mail: Mail):

1584 self._logger.debug('_decrypt_mail()')

1585

1586 if not mail.is_encrypted:

1587 self._logger.debug('mail already decrypted')

1588 return

1589

1590 self._logger.debug('body %s', mail.body)

1591

1592 # base64 decode body

1593 pub_data = b64decode(mail.body)

1594 self._logger.debug('pub_data: %s', pub_data)

1595

1596 pub_items = binary_decode(pub_data, 4)

1597 self._logger.debug('pub_items: %s', pub_items)

1598 enc_sym_key = pub_items[0x00]

1599 token = pub_items[0x01]

1600

1601 # Private key decryption

1602 sym_key = self._private_key.decrypt(

1603 enc_sym_key,

1604 padding.OAEP(

1605 mgf=padding.MGF1(algorithm=hashes.SHA256()),

1606 algorithm=hashes.SHA256(),

1607 label=None

1608 )

1609 )

1610 self._logger.debug('sym_key: %s', sym_key)

1611

1612 # Decrypt token

1613 f = Fernet(sym_key)

1614 sym_data = f.decrypt(token)

1615 # self._logger.debug('sym_data:', sym_data)

1616

1617 sym_items = binary_decode(sym_data, 2)

1618 # self._logger.debug('sym_items:', sym_items)

1619

1620 signature = sym_items[0x00]

1621 raw_body = sym_items[0x01]

1622 self._logger.debug('signature: %s', signature)

1623 self._logger.debug('raw_body: %s', raw_body)

1624

1625 # Signature Data

1626 hasher = hashes.Hash(hashes.SHA256())

1627 hasher.update(sym_key)

1628 hasher.update(raw_body)

1629 sign_token = hasher.finalize()

1630 self._logger.debug('sign_token: %s', sign_token.hex())

1631

1632 mail.is_encrypted = False

1633 mail.is_new = True

1634 mail.verified = 'n'

1635 mail.sign_hash = b64encode(sign_token).decode()

1636 mail.sign = b64encode(signature).decode()

1637 mail.decode(raw_body)

1638

1639 self._mail_db.changed()

1640

1641 def _verify_mail(self, mail: Mail, client: Client):

1642 self._logger.debug('_verify_mail()')

1643 self._logger.debug('mail: %s', mail)

1644 self._logger.debug('client: %s', client)

1645

1646 self._logger.debug('sign_hash A: %s', mail.sign_hash)

1647 sign_hash = b64decode(mail.sign_hash)

1648 self._logger.debug('sign_hash B: %s', sign_hash)

1649

1650 self._logger.debug('sign A: %s', mail.sign)

1651 sign = b64decode(mail.sign)

1652 self._logger.debug('sign B: %s', sign)

1653

1654 try:

1655 client.public_key.verify(

1656 sign,

1657 sign_hash,

1658 padding.PSS(

1659 mgf=padding.MGF1(hashes.SHA256()),

1660 salt_length=padding.PSS.MAX_LENGTH

1661 ),

1662 hashes.SHA256()

1663 )

1664 except InvalidSignature:

1665 self._logger.error('InvalidSignature')

1666 mail.verified = 'e'

1667 else:

1668 self._logger.debug('mail signature OK')

1669 mail.verified = 'y'

1670 mail.sign_hash = None

1671 mail.sign = None

1672

1673 self._mail_db.changed()

1674

1675 def get_addressbook(self) -> AddressBook:

1676 return self._address_book

1677

1678 def get_mail_db(self) -> MailDatabase:

1679 return self._mail_db

1680

1681 def get_mail_queue(self) -> MailQueue:

1682 return self._mail_queue