Debug logging in Picard 2.0

MusicBrainz Picard
1

I have a certain album that always crashes picard when I click “Lookup”.
Unfortunately I can’t press “Help” -> “view logs” -> “save as” in this situation.

the Documentation states to run the picard.exe with parameter -d to produce a debug log. Is this still valid with the 2.0 branch?

Where do I find those logs? looked in %temp%, %LOCALAPPDATA%\MusicBrainz, %APPDATA%\MusicBrainz, aswell as in the Program Files folder but I find no log.

I appreciate your help, thanks

2 Likes
2

That’s a good question. On platforms other than Windows the usual answer is to start Picard from the command line with picard -d and watch the output that is displayed on the console. Unfortunately that doesn’t work on Windows as it treats GUI apps differently and they are not attached to the console.

In past versions Picard would also write the output to a file, but AFAIK that actually was just some strange side effect and not actual intended behavior, and it caused issues. Picard 2.0 doesn’t do that.

@samj1912 @Zas Any ideas?

2 Likes
3

We already have a ticket for this https://github.com/metabrainz/picard/pull/885

I tried to solve it but no success so far.

3 Likes
4

I have a similar problem. I am trying to port my “Classical Extras” plugin over to Picard 2.0. On any individual album (or even small groups) it seems to work well, but when I try and do a whole folder-load (more than about 16 releases at a time), Picard crashes. My plugin writes its own logs (to files!) so I can see that it is not a problem with the plugin per se. However, I can’t see Picard’s log when it crashes - it used to be saved automatically in 1.4.2 - but not in 2.0 :frowning:
My problem would seem to be something to do with the way the plugin interacts with Picard, as disabling the plugin allows Picard to run OK. Loading the files with the plugin disabled, then enabling the plugin and refreshing all the releases (simultaneously), also works. It’s just loading a lot of files with the plugin enabled that causes the problem. A log from Picard might give me some clues as to what is causing this.

EDIT: Just tried to load a 2000+ track test folder without the plugin enabled and Picard 2.0 crashed. This is the same test folder that I have used countless times without any problems on Picard 1.4.2. I’ll see if I can work out which release (if any in particular) it is failing on.

3 Likes
5

OK, so I loaded the same folder again this morning (269 sub-folders - roughly one per medium). Again, this was in Picard 2.0 with no plugins running. Again it crashed, but at a different point. I had opened the log window in debug mode before running and could see which files it was loading when it crashed, so I tried just running it on that one release - which it did with no problems.
It seems to me that there is a bug somewhere in the file loading process which only occurs when loading multiple releases, but I have no idea where the problem lies. I don’t even know how this would be best described in a ticket. I assume that Picard 2.0 was stress-tested before release and that this bug did not appear.
(BTW I guess this has now strayed from the original topic, so feel free to move to a new thread).

EDIT: Now running Picard 2.0 in PyCharm. That way I get the log.
Have come across this:

  File ".\picard\ui\logview.py", line 71, in display
    for logitem in self.log_tail.contents(self.prev):
  File ".\picard\log.py", line 85, in contents
    return [x for x in self._log_queue if x.pos > prev]
  File ".\picard\log.py", line 85, in <listcomp>
    return [x for x in self._log_queue if x.pos > prev]
RuntimeError: deque mutated during iteration

Any ideas @samj1912 ?

3 Likes
6

Hey! Thank you so much for this! This is definitely helpful!

1 Like
7

@MetaTunes can you confirm if that is fixed with https://ci.appveyor.com/project/MetaBrainz/picard/build/2.0.0.dev.2.158-tasrwapi/job/q8rh8octr0pkjaqq/artifacts

8

Will look at it this evening (BST) when I get a chance. Ta.

9

The relevant PR if you are running from source https://github.com/metabrainz/picard/pull/910

1 Like
10

That seems to be working now. My test folder is now some 3000+ tracks so it took a while to load (not sure how it benchmarks vs 1.4.2), but they did all load with no crashes (and no plugins enabled).
I then enabled “Classical Extras” and refreshed them all - that took a looong time (longer than I would expect even given the 1 second per work look-up time, but the test folder has grown since the last time I did a complete reload in 1.4.2).
I’ve now restarted Picard and am doing a full load of the test folder with the plugin enabled. No crashes so far - even though some network errors are apparent. I’ll leave it to run overnight and see what happens :crossed_fingers:

UPDATE: Full load with plugin enabled - all OK - no crashes :sweat_smile:
Also, curiously, this was a lot faster than the “refresh” I tried earlier. It may be my PC was playing up, or maybe that the process is more efficient if Picard doesn’t have to handle 3000+ simultaneous refresh requests.
Anyway - good fix!

EDIT: Re the point above about the speed difference between a “refresh” and a “load”. My plugin log shows that with the “loaded” files, each release gets processed by the plugin sequentially (or at least with slightly staggered starts), whereas with the “refresh” all the releases get passed to the plugin almost simultaneously, which appears to make it run almost twice as slowly.

5 Likes