automatic-ripping-machine icon indicating copy to clipboard operation
automatic-ripping-machine copied to clipboard

[BUGFIX] Handle missing log directories more gracefully

Open alwold opened this issue 10 months ago • 4 comments

Description

I recently set up ARM on a bare metal Ubuntu 25.04 install (I'm hoping to do a writeup soon for that as well). Since there is more manual setup involved, I forgot to create the logs/progress directory, which caused the main.py script to crash inside the log cleanup function. When that happened, the exception wasn't logged in any of the logs, as far as I could tell, and the job was left in the database (and couldn't be abandoned since the PID was no longer is running).

This makes two small changes to better handle this scenario:

  • Move the calls to the cleanup function inside the try block in main.py. That way if an exception is thrown during log cleanup, it is caught, logged, and the job is cleaned up properly.
  • If any of the log directories are missing, log something and continue on to the next directory without throwing an exception.

This is my first contribution, and I'm happy to adjust the PR if anything isn't following the correct procedures, just let me know!

Type of change

Please delete options that are not relevant.

  • [x] Bug fix (non-breaking change which fixes an issue)
  • [ ] New feature (non-breaking change which adds functionality)
  • [ ] Breaking change (fix or feature that would cause existing functionality to not work as expected)
  • [ ] This change requires a documentation update

How Has This Been Tested?

Please describe the tests that you ran to verify your changes. Provide instructions so we can reproduce. Please also list any relevant details for your test configuration

  • [ ] Docker
  • [x] Other (Please state here)

I tested these on bare metal since I don't have docker, but it should be possible to test on docker as well, if you can build an image where you remove the logs/progress directory.

Change to log cleanup

  • Make sure your logs/progress directory does not exist
  • Start a rip
  • Verify that a message is logged during log cleanup indicating the progress directory was skipped
  • Verify that the rip continues

Change to top level exception handling

  • Comment out the change in logger.py to continue when a logging directory is missing
  • Start a rip
  • Verify that the job throws an exception, but it is handled and logged, and the job is properly aborted

Checklist:

  • [x] My code follows the style guidelines of this project
  • [x] I have performed a self-review of my own code
  • [x] I have commented my code, particularly in hard-to-understand areas
  • [x] I have made corresponding changes to the documentation
  • [x] My changes generate no new warnings
  • [x] I have tested that my fix is effective or that my feature works

Note: there's no functional changes in here, so documentation updates shouldn't be needed.

Changelog:

Include the details of changes made here

  • Handle missing log directories during cleanup in logger.py
  • Expand the scope of the top level try block in main.py so it handles exceptions in log cleanup

Logs

Attach logs from successful test runs here

Sample run where the logs/progress directory hasn't been created is below. Before the fix, the job would crash after the "Checking path /home/arm/logs/progress for old log files..." entry.

[06-22-2025 15:35:21] INFO ARM: ARMInfo.get_values ARM version: 2.14.0
[06-22-2025 15:35:21] INFO ARM: ARMInfo.get_values Python version: 3.13.3 (main, Jun 16 2025, 18:15:32) [GCC 14.2.0]
[06-22-2025 15:35:21] INFO ARM: ARMInfo.get_values User is: arm
[06-22-2025 15:35:21] INFO ARM: ARMInfo.get_values Alembic head is: 6870a5546912
[06-22-2025 15:35:21] INFO ARM: ARMInfo.get_values Database version is: 6870a5546912
[06-22-2025 15:35:21] INFO ARM: main.<module> ************* Starting ARM processing at 2025-06-22 15:35:21.797455 *************
[06-22-2025 15:35:21] DEBUG ARM: utils.database_adder Trying to add Job
[06-22-2025 15:35:21] DEBUG ARM: utils.database_adder successfully written Job to the database
[06-22-2025 15:35:22] DEBUG ARM: DriveUtils.update_drive_job Updating Drive: ['Drive 1'|'/dev/sr0'] Current Job: [23] Previous Job: [22]
[06-22-2025 15:35:22] DEBUG ARM: DriveUtils.update_drive_job Database update with new Job ID to associated drive
[06-22-2025 15:35:22] DEBUG ARM: main.<module> drive_mode: auto
[06-22-2025 15:35:22] DEBUG ARM: utils.database_adder Trying to add Config
[06-22-2025 15:35:22] DEBUG ARM: utils.database_adder successfully written Config to the database
[06-22-2025 15:35:22] INFO ARM: logger.clean_up_logs Looking for log files older than 1 days old.
[06-22-2025 15:35:22] INFO ARM: logger.clean_up_logs Checking path /home/arm/logs/ for old log files...
[06-22-2025 15:35:22] INFO ARM: logger.clean_up_logs Deleting log file: DUNE.log
[06-22-2025 15:35:22] INFO ARM: logger.clean_up_logs Checking path /home/arm/logs/progress for old log files...
[06-22-2025 15:35:22] INFO ARM: logger.clean_up_logs /home/arm/logs/progress is not a directory or doesn't exist. Skipping.
[06-22-2025 15:35:22] INFO ARM: main.<module> Job: FARGO_SE__16X9
[06-22-2025 15:35:22] INFO ARM: utils.clean_old_jobs Job #23 with PID 3673252 is currently running.
[06-22-2025 15:35:22] DEBUG ARM: main.log_udev_params ******************* Logging udev attributes *******************

Sample run with the fix in logger.py commented out. This would previously crash silently and the job would appear to still be in progress.

[06-22-2025 16:52:31] INFO ARM: ARMInfo.get_values ARM version: 2.14.0
[06-22-2025 16:52:31] INFO ARM: ARMInfo.get_values Python version: 3.13.3 (main, Jun 16 2025, 18:15:32) [GCC 14.2.0]
[06-22-2025 16:52:31] INFO ARM: ARMInfo.get_values User is: arm
[06-22-2025 16:52:31] INFO ARM: ARMInfo.get_values Alembic head is: 6870a5546912
[06-22-2025 16:52:31] INFO ARM: ARMInfo.get_values Database version is: 6870a5546912
[06-22-2025 16:52:31] INFO ARM: main.<module> ************* Starting ARM processing at 2025-06-22 16:52:31.501687 *************
[06-22-2025 16:52:31] DEBUG ARM: utils.database_adder Trying to add Job
[06-22-2025 16:52:31] DEBUG ARM: utils.database_adder successfully written Job to the database
[06-22-2025 16:52:32] DEBUG ARM: DriveUtils.update_drive_job Updating Drive: ['Drive 1'|'/dev/sr0'] Current Job: [24] Previous Job: [23]
[06-22-2025 16:52:32] DEBUG ARM: DriveUtils.update_drive_job Database update with new Job ID to associated drive
[06-22-2025 16:52:32] DEBUG ARM: main.<module> drive_mode: auto
[06-22-2025 16:52:32] DEBUG ARM: utils.database_adder Trying to add Config
[06-22-2025 16:52:32] DEBUG ARM: utils.database_adder successfully written Config to the database
[06-22-2025 16:52:32] INFO ARM: logger.clean_up_logs Looking for log files older than 1 days old.
[06-22-2025 16:52:32] INFO ARM: logger.clean_up_logs Checking path /home/arm/logs/ for old log files...
[06-22-2025 16:52:32] INFO ARM: logger.clean_up_logs Checking path /home/arm/logs/progress for old log files...
[06-22-2025 16:52:32] ERROR ARM: main.<module> [Errno 2] No such file or directory: '/home/arm/logs/progress'
Traceback (most recent call last):
  File "/opt/arm/arm/ripper/main.py", line 216, in <module>
    logger.clean_up_logs(cfg.arm_config["LOGPATH"], cfg.arm_config["LOGLIFE"])
    ~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/arm/arm/ripper/logger.py", line 90, in clean_up_logs
    for filename in os.listdir(log_dir):
                    ~~~~~~~~~~^^^^^^^^^
FileNotFoundError: [Errno 2] No such file or directory: '/home/arm/logs/progress'
[06-22-2025 16:52:32] ERROR ARM: main.<module> A fatal error has occurred and ARM is exiting.  See traceback below for details.
[06-22-2025 16:52:32] DEBUG ARM: utils.notify apprise message, title: ARM notification body: ARM encountered a fatal error processing None. Check the logs for more details. [Errno 2] No such file or directory: '/home/arm/logs/progress'
[06-22-2025 16:52:32] DEBUG ARM: utils.database_adder Trying to add Notifications
[06-22-2025 16:52:32] DEBUG ARM: utils.database_adder successfully written Notifications to the database
[06-22-2025 16:52:32] DEBUG ARM: job.eject Unmounted disc /dev/sr0
[06-22-2025 16:52:36] DEBUG ARM: job.eject Failed to eject /dev/sr0

alwold avatar Jun 15 '25 01:06 alwold

Thanks for making ARM better, and adding logs to your PR :)

The version script isn't working for some reason at the moment, please bump your ARM version manually

microtechno9000 avatar Jun 23 '25 12:06 microtechno9000

Sorry about the delay, can you please bump the version and we can merge ?

@1337-server ok, it's updated! Sorry for the delay on my end as well :) I'll try to keep it updated if the VERSION in main changes again.

alwold avatar Nov 19 '25 05:11 alwold