Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Assert messages to flush to the log file #923

Merged

Conversation

benmalef
Copy link
Contributor

Fixes #913

Proposed Changes

  • Updated gandlf_logging to flush the assert logs into the file using the sys.excepthook

Checklist

  • CONTRIBUTING guide has been followed.
  • PR is based on the current GaNDLF master .
  • Non-breaking change (does not break existing functionality): provide as many details as possible for any breaking change.
  • Function/class source code documentation added/updated (ensure typing is used to provide type hints, including and not limited to using Optional if a variable has a pre-defined value).
  • Code has been blacked for style consistency and linting.
  • If applicable, version information has been updated in GANDLF/version.py.
  • If adding a git submodule, add to list of exceptions for black styling in pyproject.toml file.
  • Usage documentation has been updated, if appropriate.
  • Tests added or modified to cover the changes; if coverage is reduced, please give explanation.
  • If customized dependency installation is required (i.e., a separate pip install step is needed for PR to be functional), please ensure it is reflected in all the files that control the CI, namely: python-test.yml, and all docker files [1,2,3].

Copy link
Contributor

github-actions bot commented Aug 19, 2024

MLCommons CLA bot All contributors have signed the MLCommons CLA ✍️ ✅

@sarthakpati
Copy link
Collaborator

sarthakpati commented Aug 20, 2024

Is this good to go @benmalef?

@benmalef
Copy link
Contributor Author

benmalef commented Aug 20, 2024

Is this good to go @benmalef?

@sarthakpati
It is ok, but I don't know if it is the right approach.

@sarthakpati
Copy link
Collaborator

@VukW do you have any feedback?

@VukW
Copy link
Contributor

VukW commented Aug 20, 2024

Hey folks, from a first glance it seems to be a legit way to log an exception, but to tell truth I'm confused (I've never used excepthook previously tho). let me check it a bit more deeper, cos I'm not 100% sure it should be used in this way

@sarthakpati
Copy link
Collaborator

Hey folks, from a first glance it seems to be a legit way to log an exception, but to tell truth I'm confused (I've never used excepthook previously tho). let me check it a bit more deeper, cos I'm not 100% sure it should be used in this way

Any update, @VukW?

@VukW
Copy link
Contributor

VukW commented Aug 28, 2024

@benmalef does PR work for you? For me logging.exception is not catch to the debug file...

@benmalef
Copy link
Contributor Author

@benmalef does PR work for you? For me logging.exception is not catch to the debug file...

@VukW How do you test it?
It was fine when I tested it on my PC, but I'll check it again.
Is logging.exception generally not caught, or is this only an issue in the excepthook?
Then, maybe this isn't the right approach.

@benmalef
Copy link
Contributor Author

benmalef commented Sep 12, 2024

Important Notes

I have tried using sys.excepthook to modify the behavior of the assert statement. When an AssertionError is raised, it should be printed to the console and saved in a log file. On my PC, it works well, at least for simple cases, but @VukW mentioned that it is not working properly. So, maybe this is not the right approach

Testing

I tried testing it, but pytest has its own implementation for handling AssertionError. One possible solution could be this approach, which I attempted, but I couldn’t figure it out.

Another method I tried was to modify the behavior of the assert statement in pytest. I followed some steps mentioned in this reference, but I ended up with the same result.

To disable the default behavior, you can refer to this guide.

@sarthakpati
Copy link
Collaborator

@benmalef thank you for looking into this.

@VukW: it would be great if you could provide some feedback. Until then, I would recommend we keep this PR as draft.

@VukW
Copy link
Contributor

VukW commented Sep 12, 2024

Hey folks!
Sorry for messing everything up. Right now I've checked logging again and it works as expected...

Just to be clear, I've tested config manually with a following setup.
I've taken existing gandlf anonymizer command and replaced real workload (_anonymize_images content) with the following snippet:

    logging.debug("this is logging.DEBUG")  # <- debug log
    logging.info("this is logging.INFO")  # <- debug log and stdout
    logging.warning("this is logging.WARNING")  # <- debug log and stderr
    logging.error("this is logging.ERROR")  # <- debug log and stderr
    logging.exception("this is logging.EXCEPTION")  # <- debug log and stderr
    warnings.warn("a WARNING!!")  # debug log and stderr
    logger = logging.getLogger("my-logger")
    logger.debug("this is logger.DEBUG")  # <- debug log
    logger.info("this is logger.INFO")  # <- debug log and stdout
    logger.warning("this is logger.WARNING")  # <- debug log and stderr
    logger.error("this is logger.ERROR")  # <- debug log and stderr
    logger.exception("this is logger.EXCEPTION")  # <- debug log and stderr
    raise AssertionError("test failure")  # <- debug log and stderr

Here for every record I've listed where it should be sent.
After that, I check it with:

gandlf anonymizer -i . -o . --log-file gandlf.log 1>out.log 2>err.log

Thus, I 'm able to see exactly which lines go to which log destination.
Here is the result:

out.log

The ``converters`` are currently experimental. It may not support operations including (but not limited to) Functions in ``torch.nn.functional`` that involved data dimension
�[32m2024-09-12 18:47:27 - INFO - The logs are saved in gandlf.log�[0m
�[32m2024-09-12 18:47:27 - INFO - this is logging.INFO�[0m
�[32m2024-09-12 18:47:27 - INFO - this is logger.INFO�[0m

err.log

/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/_distutils_hack/__init__.py:33: UserWarning: Setuptools is replacing distutils.
  warnings.warn("Setuptools is replacing distutils.")
2024-09-12 18:47:27 - root - WARNING - anonymizer:_anonymize_images:26 - this is logging.WARNING
2024-09-12 18:47:27 - root - ERROR - anonymizer:_anonymize_images:27 - this is logging.ERROR
2024-09-12 18:47:27 - root - ERROR - anonymizer:_anonymize_images:28 - this is logging.EXCEPTION
NoneType: None
2024-09-12 18:47:27 - py.warnings - WARNING - warnings:_showwarnmsg:109 - /mnt/c/Users/vykuk/repos/mlc/GaNDLF/GANDLF/entrypoints/anonymizer.py:29: UserWarning: a WARNING!!
  warnings.warn("a WARNING!!")  # debug log and stderr

2024-09-12 18:47:27 - my-logger - WARNING - anonymizer:_anonymize_images:33 - this is logger.WARNING
2024-09-12 18:47:27 - my-logger - ERROR - anonymizer:_anonymize_images:34 - this is logger.ERROR
2024-09-12 18:47:27 - my-logger - ERROR - anonymizer:_anonymize_images:35 - this is logger.EXCEPTION
NoneType: None
2024-09-12 18:47:27 - root - ERROR - gandlf_logging:gandlf_excepthook:34 - AssertionError: test failure
Traceback (most recent call last):
  File "/home/vukw/anaconda3/envs/env39_gandlf/bin/gandlf", line 8, in <module>
    sys.exit(gandlf())
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
  File "/mnt/c/Users/vykuk/repos/mlc/GaNDLF/GANDLF/entrypoints/anonymizer.py", line 90, in new_way
    _anonymize_images(input_dir, output_file, config, modality)
  File "/mnt/c/Users/vykuk/repos/mlc/GaNDLF/GANDLF/entrypoints/anonymizer.py", line 36, in _anonymize_images
    raise AssertionError("test failure")  # <- debug log and stderr
AssertionError: test failure

gandlf.log

Starting GaNDLF logging session 
2024-09-12 18:47:27 - root - INFO - gandlf_logging:logger_setup:59 - The logs are saved in gandlf.log
2024-09-12 18:47:27 - root - DEBUG - anonymizer:_anonymize_images:24 - this is logging.DEBUG
2024-09-12 18:47:27 - root - INFO - anonymizer:_anonymize_images:25 - this is logging.INFO
2024-09-12 18:47:27 - root - WARNING - anonymizer:_anonymize_images:26 - this is logging.WARNING
2024-09-12 18:47:27 - root - ERROR - anonymizer:_anonymize_images:27 - this is logging.ERROR
2024-09-12 18:47:27 - root - ERROR - anonymizer:_anonymize_images:28 - this is logging.EXCEPTION
NoneType: None
2024-09-12 18:47:27 - py.warnings - WARNING - warnings:_showwarnmsg:109 - /mnt/c/Users/vykuk/repos/mlc/GaNDLF/GANDLF/entrypoints/anonymizer.py:29: UserWarning: a WARNING!!
  warnings.warn("a WARNING!!")  # debug log and stderr

2024-09-12 18:47:27 - my-logger - DEBUG - anonymizer:_anonymize_images:31 - this is logger.DEBUG
2024-09-12 18:47:27 - my-logger - INFO - anonymizer:_anonymize_images:32 - this is logger.INFO
2024-09-12 18:47:27 - my-logger - WARNING - anonymizer:_anonymize_images:33 - this is logger.WARNING
2024-09-12 18:47:27 - my-logger - ERROR - anonymizer:_anonymize_images:34 - this is logger.ERROR
2024-09-12 18:47:27 - my-logger - ERROR - anonymizer:_anonymize_images:35 - this is logger.EXCEPTION
NoneType: None
2024-09-12 18:47:27 - root - ERROR - gandlf_logging:gandlf_excepthook:34 - AssertionError: test failure
Traceback (most recent call last):
  File "/home/vukw/anaconda3/envs/env39_gandlf/bin/gandlf", line 8, in <module>
    sys.exit(gandlf())
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/vukw/anaconda3/envs/env39_gandlf/lib/python3.9/site-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
  File "/mnt/c/Users/vykuk/repos/mlc/GaNDLF/GANDLF/entrypoints/anonymizer.py", line 90, in new_way
    _anonymize_images(input_dir, output_file, config, modality)
  File "/mnt/c/Users/vykuk/repos/mlc/GaNDLF/GANDLF/entrypoints/anonymizer.py", line 36, in _anonymize_images
    raise AssertionError("test failure")  # <- debug log and stderr
AssertionError: test failure

So, as you may see, everything work exactly as expected now for me... Maybe I fooled myself during previous testing

@sarthakpati
Copy link
Collaborator

sarthakpati commented Sep 12, 2024

everything work exactly as expected now for me

I think with this, we can proceed with the merge. I'll wait for the tests to finish.

@VukW unless you have any feedback, can I proceed with resolving your comments?

@VukW
Copy link
Contributor

VukW commented Sep 12, 2024

@sarthakpati sure, i don't have any other comments except already mentioned ones

Co-authored-by: Viacheslav Kukushkin <vy.kukushkin@gmail.com>
@sarthakpati sarthakpati marked this pull request as ready for review September 12, 2024 16:56
@sarthakpati sarthakpati requested a review from a team as a code owner September 12, 2024 16:56
@sarthakpati sarthakpati merged commit f26dbab into mlcommons:master Sep 12, 2024
19 checks passed
@github-actions github-actions bot locked and limited conversation to collaborators Sep 12, 2024
@benmalef benmalef deleted the assert_messages_flush_to_log_file branch September 13, 2024 06:27
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[FEATURE] How to ensure that assert messages are logged?
3 participants