Cryptoerror logs #1090

sssoleileraaa · 2020-05-08T23:24:16Z

Description

Clean up noisy logs around decryption errors: #1083 (comment)

Before

Info level

2020-05-08 16:57:36,949 - securedrop_client.api_jobs.downloads:167(_download) INFO: File downloaded to /home/creviera/.securedrop_client/data/unlike_canvas/1-unlike_canvas-msg.txt
2020-05-08 16:57:36,957 - securedrop_client.crypto:112(decrypt_submission_or_reply) ERROR: GPG Error: gpg: encrypted with RSA key, ID C3E7C4C0A2201B2A
gpg: decryption failed: No secret key

2020-05-08 16:57:36,957 - securedrop_client.api_jobs.downloads:343(call_decrypt) WARNING: Error deleting decryption directory of message 4fe17e03-8196-4700-9d40-a41164cbeb90: [Errno 39] Directory not empty: '/home/creviera/.securedrop_client/data/unlike_canvas'
2020-05-08 16:57:36,979 - securedrop_client.logic:661(on_message_download_failure) INFO: Failed to download message: Downloaded file could not be decrypted.
2020-05-08 16:57:36,980 - securedrop_client.api_jobs.base:84(_do_call_api) ERROR: MessageDownloadJob API call error: Traceback (most recent call last):
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 181, in _decrypt
    original_filename = self.call_decrypt(filepath, session)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 331, in call_decrypt
    self.gpg.decrypt_submission_or_reply(filepath, plaintext_file.name, is_doc=False)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/crypto.py", line 115, in decrypt_submission_or_reply
    raise CryptoError(msg)
securedrop_client.crypto.CryptoError: GPG Error: gpg: encrypted with RSA key, ID C3E7C4C0A2201B2A
gpg: decryption failed: No secret key


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/base.py", line 72, in _do_call_api
    result = self.call_api(api_client, session)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 133, in call_api
    self._decrypt(destination, db_object, session)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 201, in _decrypt
    ) from e
securedrop_client.api_jobs.downloads.DownloadDecryptionException: Downloaded file could not be decrypted.

2020-05-08 16:57:36,980 - securedrop_client.queue:131(process) ERROR: DownloadDecryptionException: Downloaded file could not be decrypted.

Debug level

2020-05-08 17:02:05,746 - securedrop_client.api_jobs.downloads:167(_download) INFO: File downloaded to /home/creviera/.securedrop_client/data/unsound_lateralization/1-unsound_lateralization-msg.txt
2020-05-08 17:02:05,753 - securedrop_client.crypto:112(decrypt_submission_or_reply) ERROR: GPG Error: gpg: encrypted with RSA key, ID C3E7C4C0A2201B2A
gpg: decryption failed: No secret key

2020-05-08 17:02:05,753 - securedrop_client.api_jobs.downloads:343(call_decrypt) WARNING: Error deleting decryption directory of message 457f75a1-fbcc-4116-8fbd-f35bc3dd4957: [Errno 39] Directory not empty: '/home/creviera/.securedrop_client/data/unsound_lateralization'
2020-05-08 17:02:05,772 - securedrop_client.api_jobs.downloads:196(_decrypt) DEBUG: Failed to decrypt file: 1-unsound_lateralization-msg.txt
2020-05-08 17:02:05,775 - securedrop_client.logic:661(on_message_download_failure) INFO: Failed to download message: Downloaded file could not be decrypted.
2020-05-08 17:02:05,776 - securedrop_client.api_jobs.base:84(_do_call_api) ERROR: MessageDownloadJob API call error: Traceback (most recent call last):
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 181, in _decrypt
    original_filename = self.call_decrypt(filepath, session)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 331, in call_decrypt
    self.gpg.decrypt_submission_or_reply(filepath, plaintext_file.name, is_doc=False)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/crypto.py", line 115, in decrypt_submission_or_reply
    raise CryptoError(msg)
securedrop_client.crypto.CryptoError: GPG Error: gpg: encrypted with RSA key, ID C3E7C4C0A2201B2A
gpg: decryption failed: No secret key


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/base.py", line 72, in _do_call_api
    result = self.call_api(api_client, session)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 133, in call_api
    self._decrypt(destination, db_object, session)
  File "/home/creviera/workspace/freedomofpress/securedrop-client/securedrop_client/api_jobs/downloads.py", line 201, in _decrypt
    ) from e
securedrop_client.api_jobs.downloads.DownloadDecryptionException: Downloaded file could not be decrypted.

2020-05-08 17:02:05,776 - securedrop_client.queue:131(process) ERROR: DownloadDecryptionException: Downloaded file could not be decrypted.
2020-05-08 17:02:05,778 - securedrop_client.queue:132(process) DEBUG: Skipping job

After

Info level

2020-05-08 16:37:56,812 - securedrop_client.api_jobs.downloads:167(_download) INFO: File downloaded to /home/creviera/.securedrop_client/data/condemnable_blowout/1-condemnable_blowout-msg.txt
2020-05-08 16:37:56,843 - securedrop_client.queue:131(process) ERROR: DownloadDecryptionException: Failed to decrypt file: 1-condemnable_blowout-msg.txt

Debug level

2020-05-08 16:50:13,426 - securedrop_client.api_jobs.downloads:167(_download) INFO: File downloaded to /home/creviera/.securedrop_client/data/moral_persecution/1-moral_persecution-msg.txt
2020-05-08 16:50:13,435 - securedrop_client.api_jobs.downloads:335(call_decrypt) DEBUG: Could not delete decryption directory: /home/creviera/.securedrop_client/data/moral_persecution
2020-05-08 16:50:13,455 - securedrop_client.queue:131(process) ERROR: DownloadDecryptionException: Failed to decrypt file: 1-moral_persecution-msg.txt
2020-05-08 16:50:13,456 - securedrop_client.queue:132(process) DEBUG: Skipping job

Test Plan

Follow test plan here: #1059 (comment)

Checklist

If these changes modify code paths involving cryptography, the opening of files in VMs or network (via the RPC service) traffic, Qubes testing in the staging environment is required. For fine tuning of the graphical user interface, testing in any environment in Qubes is required. Please check as applicable:

I have tested these changes in the appropriate Qubes environment
I do not have an appropriate Qubes OS workstation set up (the reviewer will need to test these changes)
These changes should not need testing in Qubes

If these changes add or remove files other than client code, the AppArmor profile may need to be updated. Please check as applicable:

I have updated the AppArmor profile
No update to the AppArmor profile is required for these changes
I don't know and would appreciate guidance

If these changes modify the database schema, you should include a database migration. Please check as applicable:

I have written a migration and upgraded a test database based on master and confirmed that the migration applies cleanly
I have written a migration but have not upgraded a test database based on master and would like the reviewer to do so
I need help writing a database migration
No database schema changes are needed

kushaldas

This looks okay to me. Approved. But,I will wait for another look from @redshiftzero before merging.

redshiftzero

one comment, otherwise lgtm!

redshiftzero · 2020-05-11T21:21:05Z

securedrop_client/api_jobs/downloads.py

-                os.path.basename(filepath), os.path.dirname(filepath))
-            )
+                type(db_object), db_object.uuid, session, original_filename=original_filename)
+            logger.info(f'File decrypted to {filepath}')


I think here in the decrypt method, on success we should provide the enclosing directory (i.e. log that the file can be found in os.path.dirname(filepath)), since the file at filepath will not exist if the user is looking for it - what do you think?

redshiftzero

thanks!

redshiftzero

restamping

sssoleileraaa marked this pull request as ready for review May 9, 2020 00:13

sssoleileraaa requested review from kushaldas and redshiftzero as code owners May 9, 2020 00:13

kushaldas previously approved these changes May 11, 2020

View reviewed changes

redshiftzero reviewed May 11, 2020

View reviewed changes

redshiftzero changed the title ~~Cryptoerro logs~~ Cryptoerror logs May 11, 2020

sssoleileraaa dismissed kushaldas’s stale review via da1f07b May 12, 2020 16:00

redshiftzero previously approved these changes May 12, 2020

View reviewed changes

Allie Crevier added 8 commits May 12, 2020 12:10

no longer log traceback in base class

727c334

cleanup crypto logs

3b16068

clean up decrypt logs

48e8120

move decrypt into try block

fb13867

update test to not check for deleted log

084a4c7

remove redundant logs from Controller

2ba00d7

update Controller tests

e51eef5

log base directory path, not full path

9449bcc

redshiftzero dismissed their stale review via 9449bcc May 12, 2020 16:12

redshiftzero force-pushed the cryptoerro-logs branch from da1f07b to 9449bcc Compare May 12, 2020 16:12

redshiftzero approved these changes May 12, 2020

View reviewed changes

redshiftzero merged commit 8798d5c into master May 12, 2020

redshiftzero deleted the cryptoerro-logs branch May 12, 2020 16:18

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Cryptoerror logs #1090

Cryptoerror logs #1090

sssoleileraaa commented May 8, 2020 •

edited

Loading

kushaldas left a comment

redshiftzero left a comment

redshiftzero May 11, 2020

redshiftzero left a comment

redshiftzero left a comment

Cryptoerror logs #1090

Cryptoerror logs #1090

Conversation

sssoleileraaa commented May 8, 2020 • edited Loading

Description

Before

Info level

Debug level

After

Info level

Debug level

Test Plan

Checklist

kushaldas left a comment

Choose a reason for hiding this comment

redshiftzero left a comment

Choose a reason for hiding this comment

redshiftzero May 11, 2020

Choose a reason for hiding this comment

redshiftzero left a comment

Choose a reason for hiding this comment

redshiftzero left a comment

Choose a reason for hiding this comment

sssoleileraaa commented May 8, 2020 •

edited

Loading