Music - Inaccurate Play History

Plex Players Mobile Devices
1

Hi everyone,

PMS: 1.18.3.2156 on Windows 10
Android: 7.26.0.14578(eaeeea5c) / OnePlus 7T (Android 10)

I listen to music at work all day every day using the Android app. As such, accurate play history is important to me. I often browse my top played list and search for songs I’ve played within the last week or month.

Recently I noticed that play history isn’t being accurately captured and thought I’d watch the PMS logs to see what’s happening (this only appears to be a problem when using Plex for Android, not the web app, Roku or other players). In a working situation, after you play a given song, this is what shows up in the log (in this case the song title is ‘A Dialogue’):

Dec 30, 2019 09:57:36.409 [16788] DEBUG - Play progress on 416072 'A Dialogue' - got played 68716 ms by account 1!
Dec 30, 2019 09:57:46.425 [17332] DEBUG - Play progress on 416072 'A Dialogue' - got played 79690 ms by account 1!
Dec 30, 2019 09:57:56.428 [16788] DEBUG - Play progress on 416072 'A Dialogue' - got played 88668 ms by account 1!
Dec 30, 2019 09:58:06.503 [17332] DEBUG - Play progress on 416072 'A Dialogue' - got played 99645 ms by account 1!
Dec 30, 2019 09:58:16.456 [14772] DEBUG - Play progress on 416072 'A Dialogue' - got played 109613 ms by account 1!
Dec 30, 2019 09:58:26.459 [17332] DEBUG - Play progress on 416072 'A Dialogue' - got played 119595 ms by account 1!
Dec 30, 2019 09:58:36.457 [14772] DEBUG - Play progress on 416072 'A Dialogue' - got played 129577 ms by account 1!
Dec 30, 2019 09:58:46.463 [17332] DEBUG - Play progress on 416072 'A Dialogue' - got played 139561 ms by account 1!
Dec 30, 2019 09:58:56.504 [14772] DEBUG - Play progress on 416072 'A Dialogue' - got played 149538 ms by account 1!
Dec 30, 2019 09:59:06.519 [16796] DEBUG - Play progress on 416072 'A Dialogue' - got played 159519 ms by account 1!
Dec 30, 2019 09:59:16.504 [14772] DEBUG - Play progress on 416072 'A Dialogue' - got played 169496 ms by account 1!
Dec 30, 2019 09:59:26.519 [16796] DEBUG - Play progress on 416072 'A Dialogue' - got played 179481 ms by account 1!
Dec 30, 2019 09:59:36.550 [16796] DEBUG - Play progress on 416072 'A Dialogue' - got played 189454 ms by account 1!
Dec 30, 2019 09:59:46.723 [16796] DEBUG - Play progress on 416072 'A Dialogue' - got played 199444 ms by account 1!
Dec 30, 2019 09:59:56.541 [14772] DEBUG - Play progress on 416072 'A Dialogue' - got played 209435 ms by account 1!
Dec 30, 2019 10:00:06.614 [16796] DEBUG - Play progress on 416072 'A Dialogue' - got played 219412 ms by account 1!
Dec 30, 2019 10:00:16.613 [17812] DEBUG - Play progress on 416072 'A Dialogue' - got played 229383 ms by account 1!
Dec 30, 2019 10:00:26.583 [16796] DEBUG - Library item 416072 'A Dialogue' got played by account 1!

PMS first records that the song is playing after 60 seconds. Then there’s an update every 10 seconds or so that it’s still playing. Finally there’s a notification that a song ‘got played’. That final line appears to be the indicator that the play history was updated successfully.

A common pattern I’ve noticed is this:

  • I’ll start to play an album
  • The first few songs will play and play history will be recorded correctly
  • After 3 - 4 songs the log for a given track will no longer finish with the ‘got played by account 1’ message (and the play history won’t be captured)
  • This pattern will play out for the remainder of the album

For example, track 4 of a particular album is called ‘Noise Of The Void’ and track 5 is ‘Dolls In the Dark’. The log looks like this:

Dec 30, 2019 10:16:13.910 [17500] DEBUG - Play progress on 416075 'Noise of the Void' - got played 262646 ms by account 1!
Dec 30, 2019 10:16:23.968 [6588] DEBUG - Play progress on 416075 'Noise of the Void' - got played 273631 ms by account 1!
Dec 30, 2019 10:16:33.946 [6588] DEBUG - Play progress on 416075 'Noise of the Void' - got played 283617 ms by account 1!
Dec 30, 2019 10:16:43.947 [17060] DEBUG - Play progress on 416075 'Noise of the Void' - got played 293600 ms by account 1!
Dec 30, 2019 10:16:53.981 [17060] DEBUG - Play progress on 416075 'Noise of the Void' - got played 303585 ms by account 1!
Dec 30, 2019 10:17:03.942 [6588] DEBUG - Play progress on 416075 'Noise of the Void' - got played 313560 ms by account 1!
Dec 30, 2019 10:17:13.939 [17060] DEBUG - Play progress on 416075 'Noise of the Void' - got played 323537 ms by account 1!
Dec 30, 2019 10:18:17.905 [11412] DEBUG - Play progress on 416076 'Dolls in the Dark' - got played 60087 ms by account 1!
Dec 30, 2019 10:18:27.891 [17060] DEBUG - Play progress on 416076 'Dolls in the Dark' - got played 70073 ms by account 1!

‘Noise Of The Void’ wasn’t skipped, it played through in its entirety, but there’s no ‘got played by account 1!’ indicator and we’re straight on to the next song (without updating the play history for ‘Noise Of The Void’).

While researching the problem I came across a post suggesting sweet fades might be an issue but I see the same thing with sweet fades turned off.

If I look at the Android log between the same time codes (see attached) I can’t find any clues.

If there’s anyone out there who can suggest something I can try / test next I’d be enormously grateful. :slight_smile:

Thank you!

plex-android.txt (19.9 KB)

1 Like
2

Interesting find. I had not noticed this before. Let me look into it and get back to you.

1 Like
3

I also notice this happening with songs the are considered short. Red Hot Chili Peppers has a song that is 14 seconds in length on the Freaky Styley disc called Thirty Dirty Birds. I can’t seem to get it to gain a play count above zero, so it sits in a smart playlist of songs that have no play count and won’t go away.

4

Interesting find. I had not noticed this before. Let me look into it and get back to you.

@anon18523487 - have you had an opportunity to investigate this by any chance? I’ve done a little more testing and there’s no difference in the behavior with synced vs un-synced content. I’m at a loss for what to do next but am happy to spend time on it. If you have any suggestions I’ll gladly listen. :slight_smile:

Many thanks again.

5

Still investigating. I’m not able to reproduce what you noticed so there is something I am missing.

6

Still investigating. I’m not able to reproduce what you noticed so there is something I am missing.

That makes me think there might be something special about my setup, although I don’t know what it could be. Again, if there’ s anything you’d like me to try please let me know. :slight_smile:

Thanks!

7

My devices are only on Android 8 or 9, not 10, so that could be the difference. I’m checking with others to see if they can reproduce on an Android 10 device.

8

That’s great - thanks very much. :slight_smile:

Out of interest, how does the play history feature work when using a mobile device in patchy network coverage? Looking at the logs it seems the client updates PMS in real time, but say you’re listening to sync’d content and lose your data connection for 3 - 4 songs. Are those plays recorded locally then batched back to PMS when the connection is restored?

Thanks again!

9

Yes, but there is a user reporting this doesn’t work for them. This also works fine for me so I haven’t been able to identify the difference. Again, might be due to a specific version of Android.

10

I see the same thing. If I stream an album on my Pixel 3, the whole album will scrobble in last.fm, but only half/two-thirds of the songs will log a play in plex play history.

I use smart playlists based on playcounts, so I would love to see this issue get fixed.

11

Same issue here.
I am running Plex server on QNAP, latest version installed 1.18.6.2368

Plex mobile app is latest version and activated.

Whenever I play content from Plex Web (Chrome) - activities are logged properly.
Whenever I play content from Plex remote - activities are still shown in Plex Web dashboard BUT IN MOST CASES NOT logged after playback is finished in Play history.

Basically, play history only shows playbacks from Plex Web, and I’ve got only one successful capture from mobile playback

I have tried Yatse as a remote - same issue, so it seems to be Server related issue.
I have logs available, so Plex support- please send me a PM and will send the logs (I do not want to publish them openly)

Capture
Capture1442×332 46.2 KB

12

@anon18523487 - anything further we can do to help debug this one? I’m ready and willing. :wink:

13

Hello!
I do have both problems too. My phone is an Android 10 phone. I can confirm the plays weren’
t batched up correct.
Also I noticed in this case, that Android sometimes stop the playback and goes back to the last song that was connected to the Server.
When in patchy network coverage this is happens very often.
Maybe this helps?
Scrobbles to last.fm are wrong for that reason too. But this is probably consequential. I am a noob in those things.
Thanks for all the help!

14

@anon18523487 - is there anything we can do to help debug this? I’m ready to help. :slightly_smiling_face:

15

I’ve been having this problem too on both mobile and Sonos. They fixed it for about 9 days then it reverted. Here’s my post on this:

16

I continue to have this issue on my Pixel 3.

If I stream from my Kindle Fire, or my work iPhone, play counts seem to log as desired.

Please let me know if there are any logs I can provide to help debug.

17

For anyone still following this thread, the new version of Plexamp appears to have changed things. I’ve been listening to music with Plexamp for the last 3 hours and every play has been successfully registered in the logs for both streamed and downloaded content. Nothing has changed when using the regular Plex app, plays stop being logged after the 4th or 5th track, so I’m thinking this shows the bug exists in the code of the regular app rather than PMS (or elsewhere).

Anyone else having a similar experience?

18

Funny, but I just ran across this issue last night, even though it is not something to which I normally pay close attention. However, I just happened to be playing around with the new Plex Dash app on my phone while listening to library radio. For whatever reason, it played a couple songs which appeared in the history in Dash, but after playing Alice Cooper “Poison”, I noticed the song didn’t show up in Dash history, even though all the succeeding songs did.

I’m up to date with respect to the server, so long story short, this issue isn’t fixed or perhaps Plex just doesn’t like Alice Cooper “Poison”. :slight_smile:

19

Yeah, I had seemed to have better luck with Plexamp.
If only plexamp supported chromecast…

20

One thing I forgot to mention was that I was listening to Library Radio via Alexa. Not sure if that would make a difference.