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

PICARD-2757: Add a command-line option to enable audit #2316

Merged
merged 10 commits into from
Sep 18, 2023

Conversation

zas
Copy link
Collaborator

@zas zas commented Sep 14, 2023

Summary

  • This is a…
    • Bug fix
    • Feature addition
    • Refactoring
    • Minor / simple change (like a typo)
    • Other
  • Describe this change in 1-2 sentences:

Problem

Solution

Using Python 3.8 sys.addaudithook()

That's a debugging feature.

Try '--audit os' or '--audit all'

Typical output would be something like:

audit:all:158721:0.24102306365966797 os.mkdir args=(b'/home/zas/.config/MusicBrainz', 511, -1)
audit:all:158721:0.24107575416564941 open args=(b'/home/zas/.config/MusicBrainz/.Picard.ini.synclock', 'a', 525377)
audit:all:158721:0.24116802215576172 fcntl.lockf args=(32, 6, None, None, 0)
audit:all:158721:0.2515387535095215 fcntl.lockf args=(32, 8, None, None, 0)

Format is audit:threadid:seconds_since_start event args

Action

@rdswift
Copy link
Collaborator

rdswift commented Sep 14, 2023

Looks like it could be a useful debugging tool.

Just a "heads up" that once it's merged we'll need to update the documentation at https://picard-docs.musicbrainz.org/en/appendices/command_line.html

@Sophist-UK
Copy link
Contributor

@zas For those of us onlookers, can you give one or two use cases showing how this might be used e.g. when someone says in the forums that they are having problems saving files and / or by Picard or Picard plugin developers?

@phw
Copy link
Member

phw commented Sep 15, 2023

@Sophist-UK One example zas showed me yesterday was to audit all calls to functions in the os module:

(.venv) ➜  picard git:(python_audit) ✗ python tagger.py -a os  
{('os',)}
audit: os.listdir with args=('/home/zas/.config/MusicBrainz/Picard/plugins',)
audit: os.listdir with args=('/home/zas/.config/MusicBrainz/Picard/plugins',)
audit: os.listdir with args=('/home/zas/src/picard/picard/plugins',)
I: 20:14:16,178 browser/browser.start:121: Starting the browser integration (127.0.0.1:8000)
audit: os.mkdir with args=(b'/home/zas/.config/MusicBrainz', 511, -1)
audit: os.mkdir with args=(b'/home/zas/.config/MusicBrainz', 511, -1)
I: 20:14:19,110 browser/browser.stop:134: Stopping the browser integration
SystemExit

Or here is a run tracking all calls to open:

% python tagger.py --audit=open 
QSocketNotifier: Can only be used with threads started with QThread
audit: open with args=('/run/user/1000/Picard_v2.10.0.dev1_main_pipe_file', 'r', 524288)
audit: open with args=('/home/phw/devel/musicbrainz/picard/locale/de/LC_MESSAGES/picard.mo', 'r', 524288)
audit: open with args=('/home/phw/devel/musicbrainz/picard/locale/de/LC_MESSAGES/picard-attributes.mo', 'r', 524288)
audit: open with args=('/home/phw/devel/musicbrainz/picard/locale/de/LC_MESSAGES/picard-constants.mo', 'r', 524288)
audit: open with args=('/home/phw/devel/musicbrainz/picard/locale/de/LC_MESSAGES/picard-countries.mo', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/acousticbrainz.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/acousticbrainz.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/acousticbrainz.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/acousticbrainz.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/acousticbrainz.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/additional_artists_variables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/additional_artists_variables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/additional_artists_variables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumartist_website.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumartist_website.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumartist_website.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumartistextension.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumartistextension.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumartistextension.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumfoldercover/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumfoldercover/__pycache__/gio.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/albumfoldercover/__pycache__/processor.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/decade.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/decade.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/decade.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/deezerart/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/deezerart/deezer/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/deezerart/deezer/__pycache__/client.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/deezerart/deezer/__pycache__/obj.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/deezerart/__pycache__/options.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/fanarttv/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/fanarttv/__pycache__/ui_options_fanarttv.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/format_performer_tags.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/format_performer_tags.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/format_performer_tags.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/format_performer_tags.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/format_performer_tags.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/happidev_lyrics.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/happidev_lyrics.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/happidev_lyrics.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/instruments.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/instruments.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/instruments.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/loadasnat.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/loadasnat.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/loadasnat.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/losslessfuncs/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/mod/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/usr/lib/python3.11/__pycache__/dataclasses.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/opencc/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/devel/musicbrainz/picard/.venv/lib/python3.11/site-packages/opencc/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/devel/musicbrainz/picard/.venv/lib/python3.11/site-packages/opencc/clib/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/papercdcase.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/papercdcase.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/papercdcase.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/picard-submit-to-listenbrainz/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/picard-submit-to-listenbrainz/__pycache__/ui_config.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/picard-submit-to-listenbrainz/__pycache__/ui_submit.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/picard-submit-to-listenbrainz/__pycache__/artist_grab.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/picard-submit-to-listenbrainz/__pycache__/listenbrainz.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/remove_perfect_albums.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/remove_perfect_albums.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/remove_perfect_albums.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/replaygain2/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/replaygain2/__pycache__/ui_options_replaygain2.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/__pycache__/rperformer.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/search_engine_lookup.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/search_engine_lookup.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/search_engine_lookup.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/search_engine_lookup.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/search_engine_lookup.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/search_engine_lookup.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/search_engine_lookup.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/__pycache__/smart_title_case.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/submit_isrc.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/submit_isrc.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/submit_isrc.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/theaudiodb.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/theaudiodb.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/theaudiodb.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/theaudiodb.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/theaudiodb.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/tracks2clipboard.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/tracks2clipboard.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/tracks2clipboard.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/viewvariables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/viewvariables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/viewvariables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/viewvariables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/viewvariables.zip', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/workandmovement/__pycache__/__init__.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/.config/MusicBrainz/Picard/plugins/workandmovement/__pycache__/roman.cpython-311.pyc', 'r', 524288)
audit: open with args=('/home/phw/devel/musicbrainz/picard/picard/ui/__pycache__/playertoolbar.cpython-311.pyc', 'r', 524288)
audit: open with args=('/proc/sys/dev/cdrom/info', 'r', 524288)
audit: open with args=('/usr/lib/python3.11/encodings/__pycache__/idna.cpython-311.pyc', 'r', 524288)
audit: open with args=('/usr/lib/python3.11/__pycache__/stringprep.cpython-311.pyc', 'r', 524288)
I: 10:55:18,913 browser/browser.start:121: Starting the browser integration (0.0.0.0:8002)
audit: open with args=(b'/home/phw/.config/MusicBrainz/.Picard.ini.synclock', 'a', 525377)
audit: open with args=(b'/home/phw/.config/MusicBrainz/.Picard.ini.synclock', 'a', 525377)
audit: open with args=('/run/user/1000/Picard_v2.10.0.dev1_main_pipe_file', 'w', 524865)
I: 10:55:21,610 browser/browser.stop:134: Stopping the browser integration

Why is it opening the plugin ZIPs so many times? That might be something to investigate.

picard/tagger.py Outdated Show resolved Hide resolved
@zas
Copy link
Collaborator Author

zas commented Sep 15, 2023

I improved (and fixed the code) a bit.

The matched prefix is now added to the line.

If you have os,os.mkdir as audit command-line option parameter it will give something like:

audit:os: os.listdir args=('/home/zas/.config/MusicBrainz/Picard/plugins',)
audit:os: os.listdir args=('/home/zas/.config/MusicBrainz/Picard/plugins',)
audit:os: os.listdir args=('/home/zas/src/picard/picard/plugins',)
audit:os.mkdir: os.mkdir args=(b'/home/zas/.config/MusicBrainz', 511, -1)

It also handles correctly os,all, all being a special keyword in this context (it matches all events).
I also dropped with args= and just print args=.

picard/tagger.py Fixed Show fixed Hide fixed
picard/tagger.py Fixed Show fixed Hide fixed
picard/tagger.py Fixed Show fixed Hide fixed
picard/tagger.py Fixed Show fixed Hide fixed
@zas zas force-pushed the python_audit branch 4 times, most recently from 5870cd2 to 20b279a Compare September 15, 2023 10:41
@zas zas requested a review from phw September 15, 2023 11:19
@zas zas force-pushed the python_audit branch 4 times, most recently from 0541560 to 3f527e7 Compare September 15, 2023 12:34
@zas zas marked this pull request as ready for review September 15, 2023 14:02
phw
phw previously approved these changes Sep 15, 2023
Copy link
Member

@phw phw left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code looks good.

This can give use a useful tool for gathering information on otherwise hard to track down issues. If unused this has no impact and the code is small enough to be no burden.

@zas zas changed the title Add a command-line option to enable audit, using Python 3.8 sys.addau… PICARD-2757: Add a command-line option to enable audit Sep 17, 2023
zas added 6 commits September 18, 2023 10:54
…dithook()

That's a debugging feature.

Try '--audit os.mkdir,open' or '--audit all'
```
audit:os:216102:48.414292335510254 os.mkdir args=(b'/home/zas/.config/MusicBrainz', 511, -1)
audit:open:216102:48.414377212524414 open args=(b'/home/zas/.config/MusicBrainz/.Picard.ini.synclock', 'a', 525377)audit:open:216130:10.849092245101929 open args=('/tmp/picardxd4csqqv.jpg', None, 655554)
audit:open:216130:10.852484703063965 open args=(58, 'w', 524865)
audit:open:216130:10.859289407730103 open args=(b'/home/zas/Musique/Budgie/The MCA Albums 1973-1975/3-02 Slipaway.flac', 'r', 524288)
audit:open:216383:10.860839128494263 open args=(b'/home/zas/Musique/Budgie/The MCA Albums 1973-1975/3-03 Who Do You Want for Your Love_.flac', 'r', 524288)

```
Not directly linked to audit events
This method isn't strictly related to events, but rather to dot-separated keys, use more generic names
@zas zas requested a review from phw September 18, 2023 09:09
@zas
Copy link
Collaborator Author

zas commented Sep 18, 2023

@phw I did some cleanup changes, can you review again? Thanks.

Copy link
Member

@phw phw left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good. Just minor comments / questions, otherwise LGTM

picard/audit.py Outdated Show resolved Hide resolved
picard/tagger.py Show resolved Hide resolved
Copy link
Member

@phw phw left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@zas zas merged commit 768b392 into metabrainz:master Sep 18, 2023
69 checks passed
@zas zas deleted the python_audit branch September 18, 2023 13:21
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants