Add debug logging, lots

Signed-off-by: Maxime “pep” Buquet <pep@bouah.net>
This commit is contained in:
Maxime “pep” Buquet 2022-02-18 14:25:26 +01:00
parent 2a9bade333
commit 02b6afe10d
Signed by: pep
GPG key ID: DEDA74AEECA9D0F2

View file

@ -381,7 +381,9 @@ class XEP_0384(BasePlugin):
return iq return iq
async def _publish_bundle(self) -> None: async def _publish_bundle(self) -> None:
log.debug('Publishing our own bundle. Do we need to?')
if self._omemo().republish_bundle: if self._omemo().republish_bundle:
log.debug('Publishing.')
iq = await self._generate_bundle_iq() iq = await self._generate_bundle_iq()
try: try:
await iq.send() await iq.send()
@ -404,8 +406,11 @@ class XEP_0384(BasePlugin):
raise raise
iq = await self._generate_bundle_iq(publish_options=False) iq = await self._generate_bundle_iq(publish_options=False)
await iq.send() await iq.send()
else:
log.debug('Not publishing.')
async def _fetch_bundle(self, jid: str, device_id: int) -> Optional[ExtendedPublicBundle]: async def _fetch_bundle(self, jid: str, device_id: int) -> Optional[ExtendedPublicBundle]:
log.debug('Fetching bundle for JID: %r, device: %r', jid, device_id)
node = '%s:%d' % (OMEMO_BUNDLES_NS, device_id) node = '%s:%d' % (OMEMO_BUNDLES_NS, device_id)
try: try:
iq = await self.xmpp['xep_0060'].get_items(jid, node) iq = await self.xmpp['xep_0060'].get_items(jid, node)
@ -417,6 +422,7 @@ class XEP_0384(BasePlugin):
async def _fetch_device_list(self, jid: JID) -> None: async def _fetch_device_list(self, jid: JID) -> None:
"""Manually query PEP OMEMO_DEVICES_NS nodes""" """Manually query PEP OMEMO_DEVICES_NS nodes"""
log.debug('Fetching device list for JID: %r', jid)
iq = await self.xmpp['xep_0060'].get_items(jid.full, OMEMO_DEVICES_NS) iq = await self.xmpp['xep_0060'].get_items(jid.full, OMEMO_DEVICES_NS)
return await self._read_device_list(jid, iq['pubsub']['items']) return await self._read_device_list(jid, iq['pubsub']['items'])
@ -492,6 +498,7 @@ class XEP_0384(BasePlugin):
}) })
try: try:
log.debug('Setting own device list to %r', device_ids)
await self.xmpp['xep_0060'].publish( await self.xmpp['xep_0060'].publish(
own_jid.bare, OMEMO_DEVICES_NS, payload=payload, options=options, own_jid.bare, OMEMO_DEVICES_NS, payload=payload, options=options,
) )
@ -675,6 +682,7 @@ class XEP_0384(BasePlugin):
# XXX: 'cipher' is part of KeyTransportMessages and is used when no payload # XXX: 'cipher' is part of KeyTransportMessages and is used when no payload
# is passed. We do not implement this yet. # is passed. We do not implement this yet.
try: try:
log.debug('Decryption: Attempt to decrypt message from JID: %r', sender)
if payload is None: if payload is None:
await self._omemo().decryptRatchetFowardingMessage( await self._omemo().decryptRatchetFowardingMessage(
jid, jid,
@ -703,8 +711,10 @@ class XEP_0384(BasePlugin):
raise NoAvailableSession(jid, sid) raise NoAvailableSession(jid, sid)
except (omemo.exceptions.TrustException,) as exn: except (omemo.exceptions.TrustException,) as exn:
if exn.problem == 'undecided': if exn.problem == 'undecided':
log.debug('Decryption: trust state for JID: %r, device: %r, is undecided', exn.bare_jid, exn.device)
raise UndecidedException(exn.bare_jid, exn.device, exn.ik) raise UndecidedException(exn.bare_jid, exn.device, exn.ik)
if exn.problem == 'untrusted': if exn.problem == 'untrusted':
log.debug('Decryption: trust state for JID: %r, device: %r, set to untrusted', exn.bare_jid, exn.device)
raise UntrustedException(exn.bare_jid, exn.device, exn.ik) raise UntrustedException(exn.bare_jid, exn.device, exn.ik)
raise raise
finally: finally:
@ -712,6 +722,7 @@ class XEP_0384(BasePlugin):
should_heartbeat = await self._should_heartbeat(sender, isPrekeyMessage) should_heartbeat = await self._should_heartbeat(sender, isPrekeyMessage)
if self.auto_heartbeat and should_heartbeat: if self.auto_heartbeat and should_heartbeat:
log.debug('Decryption: Sending hearbeat to JID: %r', jid)
async def send_heartbeat(): async def send_heartbeat():
log.debug('Sending a heartbeat message') log.debug('Sending a heartbeat message')
msg = await self.make_heartbeat(JID(jid)) msg = await self.make_heartbeat(JID(jid))
@ -757,6 +768,7 @@ class XEP_0384(BasePlugin):
expect_problems = {jid.bare: did for (jid, did) in expect_problems.items()} expect_problems = {jid.bare: did for (jid, did) in expect_problems.items()}
try: try:
log.debug('Encryption: attempt to encrypt for JIDs: %r', recipients)
if plaintext is not None: if plaintext is not None:
encrypted = await self._omemo().encryptMessage( encrypted = await self._omemo().encryptMessage(
recipients, recipients,
@ -781,18 +793,24 @@ class XEP_0384(BasePlugin):
errors = exception.problems errors = exception.problems
if errors == old_errors: if errors == old_errors:
log.debug('Encryption: Still not possible after another iteration.')
raise EncryptionPrepareException(errors) raise EncryptionPrepareException(errors)
old_errors = errors old_errors = errors
for exn in errors: for exn in errors:
if isinstance(exn, omemo.exceptions.NoDevicesException): if isinstance(exn, omemo.exceptions.NoDevicesException):
log.debug('Encryption: Missing device list for JID: %r', exn.bare_jid)
await self._fetch_device_list(JID(exn.bare_jid)) await self._fetch_device_list(JID(exn.bare_jid))
elif isinstance(exn, omemo.exceptions.MissingBundleException): elif isinstance(exn, omemo.exceptions.MissingBundleException):
log.debug('Encryption: Missing bundle for JID: %r, device: %r', exn.bare_jid, exn.device)
bundle = await self._fetch_bundle(exn.bare_jid, exn.device) bundle = await self._fetch_bundle(exn.bare_jid, exn.device)
if bundle is not None: if bundle is not None:
log.debug('Encryption: Bundle %r found!', exn.device)
devices = self.bundles.setdefault(exn.bare_jid, {}) devices = self.bundles.setdefault(exn.bare_jid, {})
devices[exn.device] = bundle devices[exn.device] = bundle
else:
log.debug('Encryption: Bundle %r not found.', exn.device)
elif isinstance(exn, omemo.exceptions.TrustException): elif isinstance(exn, omemo.exceptions.TrustException):
# On TrustException, there are two possibilities. # On TrustException, there are two possibilities.
# Either trust has not been explicitely set yet, and is # Either trust has not been explicitely set yet, and is
@ -801,6 +819,7 @@ class XEP_0384(BasePlugin):
# a choice. If untrusted, then we can safely tell the # a choice. If untrusted, then we can safely tell the
# OMEMO lib to not encrypt to this device # OMEMO lib to not encrypt to this device
if exn.problem == 'undecided': if exn.problem == 'undecided':
log.debug('Encryption: Trust state not set for JID: %r, device: %r', exn.bare_jid, exn.device)
raise UndecidedException(exn.bare_jid, exn.device, exn.ik) raise UndecidedException(exn.bare_jid, exn.device, exn.ik)
distrusted_jid = JID(exn.bare_jid) distrusted_jid = JID(exn.bare_jid)
expect_problems.setdefault(distrusted_jid, []).append(exn.device) expect_problems.setdefault(distrusted_jid, []).append(exn.device)