Send the scrobble to the client as soon as threshold has been reached

[Fratt]

Hello,

I recently updated from Multi-Scrobbler 0.4.8 to 0.8.8.

A difference I noticed is that in version 0.4.8, it used to send the scrobbles to the clients as soon as the threshold was reached (with the default value, it was about 60 seconds after playback began).

I noticed that in version 0.8.8, it was waiting for the song to be entirely over to send the scrobbler to the client, even if the threshold was reached minutes before that.

Is there a setting to revert to the old behavior ? (and immediately send the scrobbler further as soon as the threshold is reached)

Thanks a lot!

• Fratt

PS : Here is my config:
config.json

{
  "baseUrl": "https://xxx",
  "sourceDefaults": {
    "scrobbleThresholds": {
      "duration": 20,
      "percent": null
    },
    "maxPollRetries": 10,
    "maxRequestRetries": 10
  },
  "webhooks": [
        {
          "type": "gotify",
          "name": "Gotify",
          "url": "https://xxx/gotify/",
          "token": "xxx",
          "priorities": {
            "info": 5,
            "warn": 7,
            "error": 10
          }
        }
  ]
}

maloja.json

[
  {
    "name": "Maloja",
    "enable": true,
    "data": {
      "url": "https://xxx",
      "apiKey": "xxx"
    }
  }
]

spotify.json

[
  {
    "name": "Spotify",
    "enable": true,
    "clients": [],
    "data": {
      "clientId": "xxx",
      "clientSecret": "xxx",
      "redirectUri": "https://xxx/callback",
      "interval": 60
    }
  }
]

[FoxxMD]

The reason for the change is that Maloja can additionally store the actual amount of time listened to the track alongside the scrobble. In order to get this data MS needs to wait until the track is changed (or finished) to know how long it was listened to.

What is your usecase for wanting the it to scrobble as soon as the threshold is reached?

[Fratt]

Interesting, I had seen that field in Maloja but always thought it was meant to store the total length of the track, not then time spent listening to it during that scrobble.

With Multi-Scrobbler 0.4.8, I had a 99.99% success rate (= songs that I listened fully that ended up in Maloja). Since I moved to 0.8.8, I feel it's more of a 97%, and I kind of assumed that there was a link between the two, but maybe my intuition is wrong.

One scenario that feels problematic is the following :

• I start playing a 4:00 song in Spotify.
• After 2 minutes, I pause the song. (it's not yet in Maloja, at that point - would have been, with MS 0.4.8)
• The next day, I resume the same playback session in Spotify for that song (from 2:00 on), all the way to the end.

In this scenario, it feels that the scrobble is not sent to Maloja at all, in 0.8.8. (or at least, not each time)

I will run more tests and give you a reproduction scenario.

Thanks for Multi-Scrobbler, I love it!

[Fratt]

I see that you commited some improvements to logging. I'll deploy all these commits locally and come back to you next time this happens with even better logs. Thanks

[Fratt]

Sorry for the radio silence : I was on holiday for three weeks.
During my holiday, I listened to a lot of music, always listening to songs fully (never partially), and only listening to songs that were longer than 1:00. It was common that I put a song "on hold" for a few hours, right in the middle of it, and resume later. Sometimes, while leaving Spotify open, and sometimes while closing it.

The problem happened numerous times (a good 30-40 times). I'm not entirely sure, but it seems to be each time that I take a "break" in the middle of a song.

Here is an exemple of what one of those occurences look like : The song "Nightwish - The Pharaoh Sails To Orion - Live" was not scrobbled here -->

[2025-01-10 18:19:44.815 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Incoming play state ((5qJAMHuBUBO58pX6p28yWM) Nightwish - The Pharaoh Sails To Orion - Live) does not match existing state, removing existing: (2XHsN7ueEnyxg2dRANGwC4) Nightwish - Swanheart - Live
[2025-01-10 18:19:44.816 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Generating play object with playDateCompleted
[2025-01-10 18:19:44.817 +0100] VERBOSE: [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] New Play: (5qJAMHuBUBO58pX6p28yWM) Nightwish - The Pharaoh Sails To Orion - Live
[2025-01-10 18:19:44.818 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Started new Player listen range.
[2025-01-10 18:19:44.819 +0100] VERBOSE: [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] (2XHsN7ueEnyxg2dRANGwC4) Nightwish - Swanheart - Live added after met thresholds with tracked time of 120.33s (wanted 20s) and tracked percent of 52.00% (wanted 50%) and not matching any prior plays
[2025-01-10 18:19:44.843 +0100] INFO   : [App] [Sources] [Spotify - Spotify] Discovered => Nightwish - Swanheart - Live @ 2025-01-10T18:19:44+01:00 (C)
[2025-01-10 18:19:44.843 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:19:44+01:00 | Next check in 60.00s
[2025-01-10 18:20:44.921 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Access token was not valid, attempting to refresh
[2025-01-10 18:20:45.150 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Player position changed between current -> last update. Updated calculated status to playing
[2025-01-10 18:20:45.165 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:20:45+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:21:45.332 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:21:45+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:22:45.480 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:22:45+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:23:45.701 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:23:45+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:24:45.846 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Ended current Player listen range.
[2025-01-10 18:24:45.848 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:24:45+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:25:46.025 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:25:46+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:26:46.198 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:26:46+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:27:46.356 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:28:46.458 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:29:46.566 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:30:46.667 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:30:51.202 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Stale after no Play updates for 184 seconds
[2025-01-10 18:31:46.768 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 18:32:46.881 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:32:51.203 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Orphaned after no player updates for 5 minutes
[2025-01-10 18:33:46.984 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:34:47.084 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:35:47.188 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:36:47.294 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:37:47.396 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:37:51.208 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Removed after being orphaned for 5 minutes
[2025-01-10 18:38:47.505 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:39:47.633 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:40:47.738 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:41:47.852 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:42:47.977 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:43:48.088 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:44:48.208 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:45:48.316 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:46:48.422 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:47:48.524 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:48:48.632 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:49:48.735 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:50:48.833 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:51:48.956 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:52:49.059 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:53:49.167 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:54:49.267 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:55:49.365 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:56:49.477 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:57:49.599 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:58:49.729 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 18:59:49.831 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:00:49.916 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:01:50.006 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:02:50.118 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:03:50.244 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:04:50.357 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:05:50.494 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:06:50.600 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:07:50.714 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:08:50.914 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:09:51.073 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:10:51.219 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:11:51.316 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:12:51.428 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:13:51.553 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:14:51.683 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:15:51.823 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:16:51.965 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:17:52.064 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:18:52.161 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:19:52.262 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:20:52.352 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Access token was not valid, attempting to refresh
[2025-01-10 19:20:52.513 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:21:52.646 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:22:52.761 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:23:52.865 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:24:52.990 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 18:27:46+01:00 | Next check in 30.00 | No new tracks discovered
[2025-01-10 19:25:53.144 +0100] VERBOSE: [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] New Play: (5qJAMHuBUBO58pX6p28yWM) Nightwish - The Pharaoh Sails To Orion - Live
[2025-01-10 19:25:53.146 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Started new Player listen range.
[2025-01-10 19:25:53.168 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 19:25:53+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 19:26:53.326 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Incoming play state ((2NrTWe5rmT2T404IcbFDnM) Nightwish - She Is My Sin) does not match existing state, removing existing: (5qJAMHuBUBO58pX6p28yWM) Nightwish - The Pharaoh Sails To Orion - Live
[2025-01-10 19:26:53.327 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Generating play object with playDateCompleted
[2025-01-10 19:26:53.328 +0100] VERBOSE: [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] New Play: (2NrTWe5rmT2T404IcbFDnM) Nightwish - She Is My Sin
[2025-01-10 19:26:53.329 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Started new Player listen range.
[2025-01-10 19:26:53.331 +0100] VERBOSE: [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] (5qJAMHuBUBO58pX6p28yWM) Nightwish - The Pharaoh Sails To Orion - Live not added because did not meet thresholds with tracked time of 0.00s (wanted 20s) and tracked percent of 0.00% (wanted 50%).
[2025-01-10 19:26:53.342 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 19:26:53+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 19:27:53.487 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] [Player **REDACTED**-SingleUser] Player position changed between current -> last update. Updated calculated status to playing
[2025-01-10 19:27:53.503 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 19:27:53+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 19:28:53.660 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 19:28:53+01:00 | Next check in 60.00s | No new tracks discovered
[2025-01-10 19:29:53.828 +0100] DEBUG  : [App] [Sources] [Spotify - Spotify] Last activity was at 19:29:53+01:00 | Next check in 60.00s | No new tracks discovered

Any clue what's going on ?

Thanks in advance!

[FoxxMD]

HI @Fratt , sorry for all the dropped tracks. Can you try the docker image foxxmd/multi-scrobbler:pr-249 from #249 ? I believe the refactor I made for player cleanup on plex may also address the same issue you've had on spotify.

[Fratt]

Please, don't be sorry! I'm super grateful for Multi-Scrobbler and all the hours you're spending maintaining it.

I'll deploy pr-249 immediately and keep you informed in a few days if I'm still experiencing dropped tracks. Thanks a lot for the fast answer!

[Fratt]

It's been less than 48 hours, but I can already tell you that it seems to work perfectly 😍 No dropped scrobbles anymore despite a lot of long pauses in the middle of songs! I'll revert back in a few days to confirm. Thanks a LOT

[Fratt]

#249 definitely fixed the issue that made me open this thread in the first place.

Thanks a lot! <3