BUG#3844 Last.fm Scrobbler 3.1 plugin

[Owyn]

Yeah, it basically consumes 100% of available resources, which translates to 80%-90% normally. The problem is less bad then previous iterations of the last.fm plugin where my whole system became unusable, now my system remains responsive and the high CPU use is less prolonged.

That's a single core system, correct? Multi-core tends to mask the problem because you can (usually) only peg one core.

[Lowlander]

Yes, I have a single core (old laptop) system.

[stephanvdplas]

I can confirm that the problem can be pinpointed to the last.fm scrobbler plug-in. Removing it or disabling the scrobbling and MM3.1 works just fine. My machine is a bit old. But I guess this behaviour is also notably present on newer machines.
Win XP SP3.

[Peke]

@gege
3.1 plugin should fix that issue. If you can test on MM 3.1.0.1204 and plugin v 1.0.2.5 it would be great. I'm currently not in Daylight Saving Time (Central European Time [+1:00 GMT]) I would be very grateful if you can test it?

@ OTHERS regarding CPU Spike
Well, take note that last.fm plugin opens several system libraries in windows (IE libraries) to get proxy, network settings, dns, IP, direct connection to site, ...
Any AV app will strictly look as each transferred byte of data, also plugin is triggered at exact time when MM changes track, updates library, updates playcounter, ...

I have tested on PIII 800mhz, 256mb Ram, 20GB hdd and N-lited WinXP SP3 which gave me these results:
On MM track end and when last.fm plugin accesses I have little more than 1/2 sec of CPU spike to 100% which like lowlander said It was much improved from last version (1.0.1.12) where access took much more time. Adding AV to system made that cpu spike lasts even 5 sec, but even at that time MM and system was not locked.

[gege]

@gege
3.1 plugin should fix that issue. If you can test on MM 3.1.0.1204 and plugin v 1.0.2.5 it would be great. I'm currently not in Daylight Saving Time (Central European Time [+1:00 GMT]) I would be very grateful if you can test it?

Peke, I tested and it's working fine now. Thanks.

[stephanvdplas]

Well good for you Gege, but in my case it's still horrible. I uninstalled and reinstalled the last.fm 1.0.2.5 plugin, but still the max-CPU behaviour. I am indeed running MM3.1.0.1024. The MediaMonkey.exe process consumes 100% CPU and, because I'm running on a 1-CPU machine, the music runs far from smooth. I cannot even stop it (or do anything at all) until just after the start of the next track.

[Owyn]

@Peke
Looking at "LastFM_Log.txt" events logged for a single track, i.e Play Detected -> next Play Detected.

Code: Select all

23/12/2008 2:27:15 AM: Last.FM: Nowplaying Play Detected at 1230017235
23/12/2008 2:27:15 AM: Last.FM: Submit Anonymous 4 - Rondellus-De supernis sedibus
23/12/2008 2:27:15 AM: Last.FM: Submit Started
23/12/2008 2:27:16 AM: Last.FM: Submit OK
23/12/2008 2:27:16 AM: Last.FM: Session ID 74e0e0da152c4edea00dd0c663228797
23/12/2008 2:27:16 AM: Last.FM: NowPlaying Started
23/12/2008 2:27:16 AM: Last.FM: NowPlaying Anonymous 4 - Antiphon-Omnes de Saba
23/12/2008 2:27:16 AM: Last.FM: NowPlaying OK
23/12/2008 2:27:52 AM: Last.FM: Submit Started at 1230017272
23/12/2008 2:27:52 AM: Last.FM: Session ID 74e0e0da152c4edea00dd0c663228797
23/12/2008 2:27:52 AM: Last.FM: Nowplaying Play Detected at 1230017272

Are you finished all processing for a Play when the "NowPlaying OK" event is logged?

[Peke]

@stephanvdplas
Can you copy paste part of LOG file like owyn in above post where I can see what exactly Plugin is doing?

@owen
When you get log "Nowplaying Play Detected ....." plugin already have/got all needed info and then run in separate thread so MM is freed for other jobs,
same thing goes for "Submit Started at ...."
If there would be some plugin problems "Submit Started at" and "Nowplaying Play Detected" numbers would show time delay.
Same thing goes with "Last.FM: ..... Started" and line with result, from your log submit started -> OK there was less than 1s which actually resulted in <1s from plugin contact to last.fm and receiving result (OK in your case)

[Owyn]

Thanks Peke.
Was not reporting a problem. Just wanted to make sure I was interpreting the log correctly. Your explanation covered all the bases.

[Lowlander]

Code: Select all

12/24/2008 10:38:19 AM: MediaMonkey v3.1.0
12/24/2008 10:38:19 AM: Loading Last.fm Scrobbler
12/24/2008 10:38:19 AM: ----------------------------------------
12/24/2008 10:38:19 AM: Last.fm Scrobbler v1.0.2.5
12/24/2008 10:38:20 AM: ----------------------------------------
12/24/2008 11:19:14 AM: Last.FM: Nowplaying Play Detected at 1230139154
12/24/2008 11:19:14 AM: Last.FM: Handshake Session Started
12/24/2008 11:19:16 AM: Last.FM: Handshake OK
12/24/2008 11:19:16 AM: Last.FM: Handshake Session ID is abf58fd7349e426fb5a6253626def584
12/24/2008 11:19:16 AM: Last.FM: Handshake NowPlaying URL is http://post.audioscrobbler.com:80/np_1.2
12/24/2008 11:19:17 AM: Last.FM: Handshake Submission URL is http://post2.audioscrobbler.com:80/protocol_1.2
12/24/2008 11:19:18 AM: Last.FM: NowPlaying Started
12/24/2008 11:19:18 AM: Last.FM: NowPlaying Queen; Paul Rodgers - Some Things That Glitter
12/24/2008 11:19:19 AM: Last.FM: NowPlaying OK
12/24/2008 11:23:17 AM: Last.FM: Submit Started at 1230139397
12/24/2008 11:23:17 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:23:18 AM: Last.FM: Nowplaying Play Detected at 1230139398
12/24/2008 11:23:20 AM: Last.FM: Submit Queen; Paul Rodgers - Some Things That Glitter
12/24/2008 11:23:22 AM: Last.FM: Submit Started
12/24/2008 11:23:25 AM: Last.FM: Submit OK
12/24/2008 11:23:28 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:23:28 AM: Last.FM: NowPlaying Started
12/24/2008 11:23:28 AM: Last.FM: NowPlaying Queen; Paul Rodgers - C-lebrity
12/24/2008 11:23:29 AM: Last.FM: NowPlaying OK
12/24/2008 11:27:00 AM: Last.FM: Submit Started at 1230139620
12/24/2008 11:27:00 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:27:01 AM: Last.FM: Nowplaying Play Detected at 1230139621
12/24/2008 11:27:03 AM: Last.FM: Submit Queen; Paul Rodgers - C-lebrity
12/24/2008 11:27:05 AM: Last.FM: Submit Started
12/24/2008 11:27:08 AM: Last.FM: Submit OK
12/24/2008 11:27:09 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:27:09 AM: Last.FM: NowPlaying Started
12/24/2008 11:27:09 AM: Last.FM: NowPlaying Queen; Paul Rodgers - Through The Night
12/24/2008 11:27:10 AM: Last.FM: NowPlaying OK
12/24/2008 11:32:03 AM: Last.FM: Submit Started at 1230139923
12/24/2008 11:32:03 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:32:04 AM: Last.FM: Nowplaying Play Detected at 1230139923
12/24/2008 11:32:06 AM: Last.FM: Submit Queen; Paul Rodgers - Through The Night
12/24/2008 11:32:08 AM: Last.FM: Submit Started
12/24/2008 11:32:11 AM: Last.FM: Submit OK
12/24/2008 11:32:13 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:32:14 AM: Last.FM: NowPlaying Started
12/24/2008 11:32:14 AM: Last.FM: NowPlaying Queen; Paul Rodgers - Say It's Not True
12/24/2008 11:32:14 AM: Last.FM: NowPlaying OK
12/24/2008 11:36:11 AM: Last.FM: Submit Started at 1230140171
12/24/2008 11:36:11 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:36:11 AM: Last.FM: Nowplaying Play Detected at 1230140171
12/24/2008 11:36:23 AM: Last.FM: Submit Queen; Paul Rodgers - Say It's Not True
12/24/2008 11:36:25 AM: Last.FM: Submit Started
12/24/2008 11:36:29 AM: Last.FM: Submit OK
12/24/2008 11:36:32 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:36:33 AM: Last.FM: NowPlaying Started
12/24/2008 11:36:33 AM: Last.FM: NowPlaying Queen; Paul Rodgers - Surf's Up...School's Out !
12/24/2008 11:36:33 AM: Last.FM: NowPlaying OK
12/24/2008 11:42:29 AM: Last.FM: Submit Started at 1230140549
12/24/2008 11:42:29 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:42:29 AM: Last.FM: Nowplaying Play Detected at 1230140549
12/24/2008 11:42:39 AM: Last.FM: Submit Queen; Paul Rodgers - Surf's Up...School's Out !
12/24/2008 11:42:43 AM: Last.FM: Submit Started
12/24/2008 11:42:53 AM: Last.FM: Submit OK
12/24/2008 11:43:02 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:43:03 AM: Last.FM: NowPlaying Started
12/24/2008 11:43:03 AM: Last.FM: NowPlaying Queen; Paul Rodgers - Small reprise
12/24/2008 11:43:05 AM: Last.FM: NowPlaying OK
12/24/2008 11:44:51 AM: Last.FM: Submit Started at 1230140691
12/24/2008 11:44:51 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:44:51 AM: Last.FM: Nowplaying Play Detected at 1230140691
12/24/2008 11:44:55 AM: Last.FM: Submit Queen; Paul Rodgers - Small reprise
12/24/2008 11:44:57 AM: Last.FM: Submit Started
12/24/2008 11:45:00 AM: Last.FM: Submit OK
12/24/2008 11:45:05 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:45:05 AM: Last.FM: NowPlaying Started
12/24/2008 11:45:05 AM: Last.FM: NowPlaying Il Divo - The Power Of Love
12/24/2008 11:45:05 AM: Last.FM: NowPlaying OK
12/24/2008 11:49:56 AM: Last.FM: Submit Started at 1230140996
12/24/2008 11:49:56 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:49:56 AM: Last.FM: Nowplaying Play Detected at 1230140996
12/24/2008 11:49:58 AM: Last.FM: Submit Il Divo - The Power Of Love
12/24/2008 11:50:04 AM: Last.FM: Submit Started
12/24/2008 11:50:09 AM: Last.FM: Submit OK
12/24/2008 11:50:13 AM: Last.FM: Session ID abf58fd7349e426fb5a6253626def584
12/24/2008 11:50:13 AM: Last.FM: NowPlaying Started
12/24/2008 11:50:14 AM: Last.FM: NowPlaying Il Divo - La Promessa
12/24/2008 11:50:14 AM: Last.FM: NowPlaying OK

Just in case it's of interest. And yes during high CPU use MediaMonkey is unusable, which can last 20+ seconds.

[Peke]

@lowlander
I see few seconds delay from Submitting to Now playing starting. I'll check if I could squeeze some additional Log MSGs to see what exactly is happening in that exact time as nowplaying is waiting that Submitting gets finished prior to sending new nowplaying track. I'm guessing that in that time MM gets high CPU usage even that means that something interfere with plugin process thread. I wonder can you do small test and do several quick track skips (with 1 sec delay) to initiate multiple nowplaying sending in short period of time and then watch CPU Usage?

[Lowlander]

Skipping to the next song or skipping ahead and let MediaMonkey switch to the next track don't show this spike in CPU, it just happens when a track is fully played and changed to the next.

Just in case the log is useful:

Code: Select all

12/24/2008 8:40:23 PM: MediaMonkey v3.1.0
12/24/2008 8:40:23 PM: Loading Last.fm Scrobbler
12/24/2008 8:40:23 PM: ----------------------------------------
12/24/2008 8:40:23 PM: Last.fm Scrobbler v1.0.2.5
12/24/2008 8:40:23 PM: ----------------------------------------
12/24/2008 8:50:04 PM: Last.FM: Nowplaying Play Detected at 1230173404
12/24/2008 8:50:04 PM: Last.FM: Handshake Session Started
12/24/2008 8:50:05 PM: Last.FM: Handshake OK
12/24/2008 8:50:05 PM: Last.FM: Handshake Session ID is 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:05 PM: Last.FM: Handshake NowPlaying URL is http://post.audioscrobbler.com:80/np_1.2
12/24/2008 8:50:05 PM: Last.FM: Handshake Submission URL is http://post2.audioscrobbler.com:80/protocol_1.2
12/24/2008 8:50:05 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:06 PM: Last.FM: NowPlaying Il Divo - La Luna
12/24/2008 8:50:09 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:14 PM: Last.FM: Nowplaying Play Detected at 1230173414
12/24/2008 8:50:14 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:15 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:15 PM: Last.FM: NowPlaying Il Divo - She
12/24/2008 8:50:16 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:17 PM: Last.FM: Nowplaying Play Detected at 1230173417
12/24/2008 8:50:18 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:18 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:18 PM: Last.FM: NowPlaying Pink - So What
12/24/2008 8:50:18 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:19 PM: Last.FM: Nowplaying Play Detected at 1230173419
12/24/2008 8:50:19 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:20 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:20 PM: Last.FM: NowPlaying Katy Perry - Hot N Cold
12/24/2008 8:50:20 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:21 PM: Last.FM: Nowplaying Play Detected at 1230173421
12/24/2008 8:50:21 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:21 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:21 PM: Last.FM: NowPlaying The Pussycat Dolls - When I Grow Up
12/24/2008 8:50:22 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:23 PM: Last.FM: Nowplaying Play Detected at 1230173423
12/24/2008 8:50:23 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:24 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:24 PM: Last.FM: NowPlaying Rihanna - Disturbia
12/24/2008 8:50:24 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:25 PM: Last.FM: Nowplaying Play Detected at 1230173425
12/24/2008 8:50:26 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:26 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:26 PM: Last.FM: NowPlaying Ne-Yo - Closer
12/24/2008 8:50:27 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:27 PM: Last.FM: Nowplaying Play Detected at 1230173427
12/24/2008 8:50:28 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:28 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:28 PM: Last.FM: NowPlaying Chris Brown - Forever
12/24/2008 8:50:29 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:39 PM: Last.FM: Nowplaying Play Detected at 1230173439
12/24/2008 8:50:39 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:39 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:39 PM: Last.FM: NowPlaying Kardinal Offishall; Akon - Dangerous
12/24/2008 8:50:40 PM: Last.FM: NowPlaying OK
12/24/2008 8:50:50 PM: Last.FM: Nowplaying Play Detected at 1230173450
12/24/2008 8:50:50 PM: Last.FM: Session ID 7c3867a6a15b47c4aec83662d6dd93fe
12/24/2008 8:50:51 PM: Last.FM: NowPlaying Started
12/24/2008 8:50:51 PM: Last.FM: NowPlaying T.I. - Whatever You Like
12/24/2008 8:50:51 PM: Last.FM: NowPlaying OK

[Peke]

THX, I'll check if there is some way to log things better.

[xtaticace]

I don't know if I am posting this at the correct location but is it possible to integrate the script so that it would tag 'love track' on last.fm if that track has a rating of 4.5 stars or better?


I tried to post in "Re: Last.fm Scrobbler 3.1 plugin" but it redirected me here so I posted the request here.

[Owyn]

I tried to post in "Re: Last.fm Scrobbler 3.1 plugin" but it redirected me here so I posted the request here.

The topic titles in the Beta forum are frequently updated to reflect Mantis links and fix status. No redirect, just a change in topic title since the post you linked to was made.