Skip to content

Commit

Permalink
Merge pull request #36 from freedomofpress/logging-logger
Browse files Browse the repository at this point in the history
Use logger instead of logging consistently accross the scripts
  • Loading branch information
redshiftzero authored Dec 5, 2019
2 parents ae8e16f + ed81efc commit f561bd8
Show file tree
Hide file tree
Showing 3 changed files with 47 additions and 42 deletions.
6 changes: 4 additions & 2 deletions securedrop_export/entrypoint.py
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,8 @@
CONFIG_PATH = "/etc/sd-export-config.json"
DEFAULT_HOME = os.path.join(os.path.expanduser("~"), ".securedrop_export")

logger = logging.getLogger(__name__)


def configure_logging():
"""
Expand Down Expand Up @@ -44,13 +46,13 @@ def start():
msg = "ERROR_LOGGING"
export.SDExport.exit_gracefully(msg)

logging.info('Starting SecureDrop Export {}'.format(__version__))
logger.info('Starting SecureDrop Export {}'.format(__version__))
my_sub = export.SDExport(sys.argv[1], CONFIG_PATH)

try:
# Halt immediately if target file is absent
if not os.path.exists(my_sub.archive):
logging.info('Archive is not found {}.'.format(my_sub.archive))
logger.info('Archive is not found {}.'.format(my_sub.archive))
msg = "ERROR_FILE_NOT_FOUND"
my_sub.exit_gracefully(msg)
main.__main__(my_sub)
Expand Down
61 changes: 32 additions & 29 deletions securedrop_export/export.py
Original file line number Diff line number Diff line change
Expand Up @@ -82,27 +82,27 @@ def __init__(self, archive_path):

try:
with open(self.metadata_path) as f:
logging.info('Parsing archive metadata')
logger.info('Parsing archive metadata')
json_config = json.loads(f.read())
self.export_method = json_config.get("device", None)
self.encryption_method = json_config.get("encryption_method", None)
self.encryption_key = json_config.get(
"encryption_key", None
)
logging.info(
logger.info(
'Exporting to device {} with encryption_method {}'.format(
self.export_method, self.encryption_method
)
)

except Exception:
logging.error('Metadata parsing failure')
logger.error('Metadata parsing failure')
raise

def is_valid(self):
logging.info('Validating metadata contents')
logger.info('Validating metadata contents')
if self.export_method not in self.SUPPORTED_EXPORT_METHODS:
logging.error(
logger.error(
'Archive metadata: Export method {} is not supported'.format(
self.export_method
)
Expand All @@ -111,7 +111,7 @@ def is_valid(self):

if self.export_method == "disk":
if self.encryption_method not in self.SUPPORTED_ENCRYPTION_METHODS:
logging.error(
logger.error(
'Archive metadata: Encryption method {} is not supported'.format(
self.encryption_method
)
Expand Down Expand Up @@ -185,7 +185,7 @@ def popup_message(self, msg):

def extract_tarball(self):
try:
logging.info('Extracting tarball {} into {}'.format(self.archive, self.tmpdir))
logger.info('Extracting tarball {} into {}'.format(self.archive, self.tmpdir))
with tarfile.open(self.archive) as tar:
tar.extractall(self.tmpdir)
except Exception:
Expand All @@ -195,17 +195,20 @@ def check_usb_connected(self, exit=False) -> None:
usb_devices = self._get_connected_usbs()

if len(usb_devices) == 0:
logger.info('0 USB devices connected')
self.exit_gracefully(ExportStatus.USB_NOT_CONNECTED.value)
elif len(usb_devices) == 1:
logger.info('1 USB device connected')
self.device = usb_devices[0]
if exit:
self.exit_gracefully(ExportStatus.USB_CONNECTED.value)
elif len(usb_devices) > 1:
logger.info('>1 USB devices connected')
# Return generic error until freedomofpress/securedrop-export/issues/25
self.exit_gracefully(ExportStatus.ERROR_GENERIC.value)

def _get_connected_usbs(self) -> List[str]:
logging.info('Performing usb preflight')
logger.info('Performing usb preflight')
# List all block devices attached to VM that are disks and not partitions.
try:
lsblk = subprocess.Popen(["lsblk", "-o", "NAME,TYPE"], stdout=subprocess.PIPE,
Expand Down Expand Up @@ -243,7 +246,7 @@ def set_extracted_device_name(self):
# we don't support multiple partitions
partition_count = device_and_partitions.decode('utf-8').split('\n').count('part')
if partition_count > 1:
logging.debug("multiple partitions not supported")
logger.debug("multiple partitions not supported")
self.exit_gracefully(ExportStatus.USB_ENCRYPTION_NOT_SUPPORTED.value)

# redefine device to /dev/sda if disk is encrypted, /dev/sda1 if partition encrypted
Expand All @@ -254,9 +257,9 @@ def set_extracted_device_name(self):
def check_luks_volume(self):
# cryptsetup isLuks returns 0 if the device is a luks volume
# subprocess with throw if the device is not luks (rc !=0)
logging.info('Checking if volume is luks-encrypted')
logger.info('Checking if volume is luks-encrypted')
self.set_extracted_device_name()
logging.debug("checking if {} is luks encrypted".format(self.device))
logger.debug("checking if {} is luks encrypted".format(self.device))
self.safe_check_call(
command=["sudo", "cryptsetup", "isLuks", self.device],
error_message=ExportStatus.USB_ENCRYPTION_NOT_SUPPORTED.value
Expand All @@ -276,18 +279,18 @@ def unlock_luks_volume(self, encryption_key):

# the luks device is not already unlocked
if not os.path.exists(os.path.join("/dev/mapper/", self.encrypted_device)):
logging.debug('Unlocking luks volume {}'.format(self.encrypted_device))
logger.debug('Unlocking luks volume {}'.format(self.encrypted_device))
p = subprocess.Popen(
["sudo", "cryptsetup", "luksOpen", self.device, self.encrypted_device],
stdin=subprocess.PIPE,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE
)
logging.debug('Passing key')
logger.debug('Passing key')
p.communicate(input=str.encode(encryption_key, "utf-8"))
rc = p.returncode
if rc != 0:
logging.error('Bad phassphrase for {}'.format(self.encrypted_device))
logger.error('Bad phassphrase for {}'.format(self.encrypted_device))
self.exit_gracefully(ExportStatus.USB_BAD_PASSPHRASE.value)
except subprocess.CalledProcessError:
self.exit_gracefully(ExportStatus.USB_ENCRYPTION_NOT_SUPPORTED)
Expand All @@ -301,7 +304,7 @@ def mount_volume(self):
)

mapped_device_path = os.path.join("/dev/mapper/", self.encrypted_device)
logging.info('Mounting {}'.format(mapped_device_path))
logger.info('Mounting {}'.format(mapped_device_path))
self.safe_check_call(
command=["sudo", "mount", mapped_device_path, self.mountpoint],
error_message=ExportStatus.ERROR_USB_MOUNT.value
Expand All @@ -319,24 +322,24 @@ def copy_submission(self):
target_path = os.path.join(self.mountpoint, self.target_dirname)
subprocess.check_call(["mkdir", target_path])
export_data = os.path.join(self.tmpdir, "export_data/")
logging.info('Copying file to {}'.format(self.target_dirname))
logger.info('Copying file to {}'.format(self.target_dirname))
subprocess.check_call(["cp", "-r", export_data, target_path])
logging.info('File copied successfully to {}'.format(self.target_dirname))
logger.info('File copied successfully to {}'.format(self.target_dirname))
self.popup_message("Files exported successfully to disk.")
except (subprocess.CalledProcessError, OSError):
self.exit_gracefully(ExportStatus.ERROR_USB_WRITE.value)
finally:
# Finally, we sync the filesystem, unmount the drive and lock the
# luks volume, and exit 0
logging.info('Syncing filesystems')
logger.info('Syncing filesystems')
subprocess.check_call(["sync"])
logging.info('Unmounting drive from {}'.format(self.mountpoint))
logger.info('Unmounting drive from {}'.format(self.mountpoint))
subprocess.check_call(["sudo", "umount", self.mountpoint])
logging.info('Locking luks volume {}'.format(self.encrypted_device))
logger.info('Locking luks volume {}'.format(self.encrypted_device))
subprocess.check_call(
["sudo", "cryptsetup", "luksClose", self.encrypted_device]
)
logging.info('Deleting temporary directory {}'.format(self.tmpdir))
logger.info('Deleting temporary directory {}'.format(self.tmpdir))
subprocess.check_call(["rm", "-rf", self.tmpdir])
sys.exit(0)

Expand All @@ -348,17 +351,17 @@ def wait_for_print(self):
printer_idle_string = "printer {} is idle".format(self.printer_name)
while True:
try:
logging.info('Running lpstat waiting for printer {}'.format(self.printer_name))
logger.info('Running lpstat waiting for printer {}'.format(self.printer_name))
output = subprocess.check_output(["lpstat", "-p", self.printer_name])
if printer_idle_string in output.decode("utf-8"):
logging.info('Print completed')
logger.info('Print completed')
return True
else:
time.sleep(5)
except subprocess.CalledProcessError:
self.exit_gracefully(ExportStatus.ERROR_PRINT.value)
except TimeoutException:
logging.error('Timeout waiting for printer {}'.format(self.printer_name))
logger.error('Timeout waiting for printer {}'.format(self.printer_name))
self.exit_gracefully(ExportStatus.ERROR_PRINT.value)
return True

Expand All @@ -374,19 +377,19 @@ def get_printer_uri(self):
for line in output.split():
if "usb://" in line.decode("utf-8"):
printer_uri = line.decode("utf-8")
logging.info('lpinfo usb printer: {}'.format(printer_uri))
logger.info('lpinfo usb printer: {}'.format(printer_uri))

# verify that the printer is supported, else exit
if printer_uri == "":
# No usb printer is connected
logging.info('No usb printers connected')
logger.info('No usb printers connected')
self.exit_gracefully(ExportStatus.ERROR_PRINTER_NOT_FOUND.value)
elif not any(x in printer_uri for x in ("Brother", "LaserJet")):
# printer url is a make that is unsupported
logging.info('Printer {} is unsupported'.format(printer_uri))
logger.info('Printer {} is unsupported'.format(printer_uri))
self.exit_gracefully(ExportStatus.ERROR_PRINTER_NOT_SUPPORTED.value)

logging.info('Printer {} is supported'.format(printer_uri))
logger.info('Printer {} is supported'.format(printer_uri))
return printer_uri

def install_printer_ppd(self, uri):
Expand Down Expand Up @@ -505,7 +508,7 @@ def print_file(self, file_to_print):
)
file_to_print = converted_path

logging.info('Sending file to printer {}:{}'.format(self.printer_name, file_to_print))
logger.info('Sending file to printer {}:{}'.format(self.printer_name, file_to_print))
self.safe_check_call(
command=["xpp", "-P", self.printer_name, file_to_print],
error_message=ExportStatus.ERROR_PRINT.value
Expand Down
22 changes: 11 additions & 11 deletions securedrop_export/main.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,34 +16,34 @@ def __main__(submission):

if submission.archive_metadata.is_valid():
if submission.archive_metadata.export_method == "usb-test":
logging.info('Export archive is usb-test')
logger.info('Export archive is usb-test')
submission.check_usb_connected(exit=True)
elif submission.archive_metadata.export_method == "disk":
logging.info('Export archive is disk')
logger.info('Export archive is disk')
# check_usb_connected looks for the drive, sets the drive to use
submission.check_usb_connected()
logging.info('Unlocking volume')
logger.info('Unlocking volume')
# exports all documents in the archive to luks-encrypted volume
submission.unlock_luks_volume(submission.archive_metadata.encryption_key)
logging.info('Mounting volume')
logger.info('Mounting volume')
submission.mount_volume()
logging.info('Copying submission to drive')
logger.info('Copying submission to drive')
submission.copy_submission()
elif submission.archive_metadata.export_method == "disk-test":
logging.info('Export archive is disk-test')
logger.info('Export archive is disk-test')
# check_usb_connected looks for the drive, sets the drive to use
submission.check_usb_connected()
submission.check_luks_volume()
elif submission.archive_metadata.export_method == "printer":
logging.info('Export archive is printer')
logger.info('Export archive is printer')
# prints all documents in the archive
logging.info('Searching for printer')
logger.info('Searching for printer')
printer_uri = submission.get_printer_uri()
logging.info('Installing printer drivers')
logger.info('Installing printer drivers')
printer_ppd = submission.install_printer_ppd(printer_uri)
logging.info('Setting up printer')
logger.info('Setting up printer')
submission.setup_printer(printer_uri, printer_ppd)
logging.info('Printing files')
logger.info('Printing files')
submission.print_all_files()
elif submission.archive_metadata.export_method == "printer-test":
# Prints a test page to ensure the printer is functional
Expand Down

0 comments on commit f561bd8

Please sign in to comment.