Google Music Keeps Refreshing Continuously in Chrome

[zigmachine]

While navigating Google Music in the browser (Chrome) the page keeps refreshing over and over (about every 5 seconds).
Not sure why it's polling this often, I believe it should be once a minute. This is making it difficult to navigate around Google Music on the browser.
It seems the issue is only on the browser, on my iPhone the playlists are updating perfectly.

[simon-weber]

Sorry for the trouble! This sounds a bit like #17.

Two things that might help us narrow it down:

• can you check the background script logs to see what the syncs are doing (click the "background page" link by the "Inspect views" section on chrome://extensions)? It may be trying to add/delete a small number of tracks over and over.
• can you provide the playlist definitions you're using? "last played" in particular can be troublesome sometimes ("last played" playlists cut off tracks that are playing when updating the playlist #18), so I'd like to rule that out.

There's also a chance that this is caused by concurrency issues between periodic sync and another sync, but that seems less likely to me.

[zigmachine]

I think you are on the right track. Here is the log:
log.txt

My playlist parameters are:
Year: Greater than or equal to 2010
Year: Less than or equal to 2019
Rating : Greater than 4

Sort by Play Count descending

[simon-weber]

Huh, so it looks like it's trying and failing to add the same track over and over:

$ grep 'adding 1' ~/Downloads/zigmachine.log
googlemusic.js:162 adding 1
googlemusic.js:162 adding 1
googlemusic.js:162 adding 1
googlemusic.js:162 adding 1
googlemusic.js:162 adding 1
googlemusic.js:162 adding 1
...

Let's see if there's anything different about this track, since that's also caused issues in the past (#10). Here's one way you could do it:

• select the network tab from the background script inspector (where the log is).
• select one of the addtrackstoplaylist requests, then scroll down to the request params at the bottom.
• the requests are of the form [["<sessionid>",1],["<listid>",[["<store id or songid>",tracktype]]]]. Pick out the track id.
• create a playlist with id equals your-track-id, hit "test", then copy and paste the json output back here.

[zigmachine]

Thanks for the quick reply.
I think I may be doing something wrong.

I followed your instructions and got the following from the Form Data section:

[["",1],["a9fc8542-3347-4845-b49b-f543d6ee50d8",[["Ttrtmzbwlnzdsrgi4l4baoqqegi",7]]]]:

But when I try to TEST the playlist I get this:

query found 0 first was
undefined

[simon-weber]

Hm, I was expecting to see a playlist id of bbd5f87b-b34a-30cb-8f0f-502c15abc193 to match the logs. Do you have other requests containing that? Also, is the count of tracks in Google's interface 207 (one less than autoplaylists wants)?

There's a chance it was some failure on Google's end involving the particular track, and it's working now, in which case reducing sync retries may be a good enough fix.

[zigmachine]

Ok, I tried running it on that playlist id and I'm getting:

query found 1 first was
{
"id": "bbd5f87b-b34a-30cb-8f0f-502c15abc193",
"title": "Shy Boy",
"artist": "JD McPherson",
"album": "Let The Good Times Roll",
"albumArtist": "JD McPherson",
"composer": "JD McPherson",
"genre": "Rock",
"durationMillis": 174000,
"track": 7,
"disc": 1,
"totalDiscs": 1,
"year": 2015,
"playCount": 98,
"rating": 5,
"creationDate": 1426691245272734,
"lastPlayed": 1449764681572931,
"storeId": "Tjtakaj7tsy6atcaon3szxbclqi",
"type": 7
}

Google's interface is showing 207, but autoplaylist wants 208.

[simon-weber]

Oh, shoot, I copied the wrong id. The playlist id from the logs is ed1f8500-06e8-4e09-b6f4-f43c9c537829, which I was expecting to see in your paste from the form data section (the id I pasted earlier was the first matching song, which likely isn't the one we're looking for).

If you can't find that playlist id in other requests, then maybe you've deleted the playlist since the first time? In that case, we may have the correct id with Ttrtmzbwlnzdsrgi4l4baoqqegi. You can try creating a playlist with storeId equals Ttrtmzbwlnzdsrgi4l4baoqqegi -- my first suggestion didn't accommodate All Access ids.

[johnrobertlawson]

Also have this same issue (as you know from the older issues), and wondered if @zigmachine uses the extension on two or more desktop devices? I do, and only noticed the constant refreshing when I turned on the extension on my second Chrome-running device.

[zigmachine]

Yes, I am using it at work and home.
However, I installed it at home first and noticed the issue there before using at work.

I've been trying to find any of the problem songs using the tips that @simon-weber provided.
Haven't been able to solve it yet. But I'm still at it.

[simon-weber]

@johnrobertlawson the multiple extension issue isn't one I've thought about yet (though I'm not surprised it causes issues, haha).

We could use chrome sync storage to lock an account, but that would only work for folks with sync enabled.

[simon-weber]

@zigmachine I've just published https://github.com/simon-weber/Autoplaylists-for-Google-Music/releases/tag/0.2.0 with the linked changes. The first two will lessen your symptoms, while the last should help us find the problematic track: now instead of cross-referencing the network tab, we'll be able to find the track id right in the log (it'll say "adding X tracks, first 10 are...").

Update to it when you've got a chance, and we can look into this further.

[simon-weber]

Bump! Have you had a chance to try out the new version? I'm looking to cut another release soon and it'd be nice to have a fix for this issue in it.

[johnrobertlawson]

There's definitely less CPU usage now, and less time refreshing in Chrome.

[simon-weber]

Ok, I'm going to close this then. Feel free to reopen if it's still a problem.

[johnrobertlawson]

I'm afraid this is an issue again. Even when I'm messing around with non-autoplaylists, it constantly refreshes every 5-10 seconds and resets whatever sorting I've got, and scrolls to the top.

[simon-weber]

Hm. Can you check the logs to see what operations it's performing repeatedly? The logs should be more informative this time around.

[johnrobertlawson]

Hmm, this rings a bell...

first is Object {id: "dd612f5e-425b-3159-a6ea-eb06c93ce335", title: "Down To The Cellar", artist: "dredg", album: "The Pariah, The Parrot, The Delusion", albumArtist: "dredg"…}
googlemusic.js:218 load response [Array[3], Array[1]]
googlemusic.js:317 no need to delete pre-filter; adding
googlemusic.js:182 adding 224 tracks. first 10 are [Object, Object, Object, Object, Object, Object, Object, Object, Object, Object]
googlemusic.js:191 add response [Array[3], Array[2]]
background.js:138 not a 0-track add; retrying syncPlaylist [Array[3], Array[2]]
background.js:31 index for 07953966069546500216 0
background.js:103 syncPlaylist, attempt 3
background.js:121 lock Old Faves
background.js:123 Old Faves found 611

[johnrobertlawson]

My last post was probably useless, sorry.

It freezes/refreshes after two commands in particular:
"unlock [playlist name]"
"adding [#] tracks" and before "giving up on syncPlaylist!"

But not every time, as I watch the logs with the G Music screen open.

[simon-weber]

Gotcha. Some questions:

• when "adding X tracks" appears a lot, does the number change each time? The expected behavior is for it to decrease over time, and reach 0 before we give up.
• if the number stays the same, can you try expanding the "first 10 are..." objects and pasting the tracks here? There may be something weird about them that's preventing them from being added to the playlist (as was the case with AA tracks originally).

[johnrobertlawson]

The number stays the same or increasing.

The tracks are the top 10 of my "Not played in 60 days + thumbs up" and in descending order of play count. I notice:

• All the tracks are ones I uploaded from my collection (is that Type 2?)
• Some have storeIds, some don't.

The rest seems pretty random - I can link you to the log copy, though I can't find a way to expand the log objects and pasting while preserving indentation? Sorry, not a web programmer!

[simon-weber]

Increasing is pretty surprising.

I can't find a way to expand the log objects and paste while preserving indentation

I don't know of any way either =/ Don't worry about the indentation, I can always clean it up on my end if I need to.

Can you also try to expand the "add response" bit and paste it? I wonder if Google is telling us anything about the tracks in the response.

[johnrobertlawson]

It's hard to see which specific add response corresponds to the refreshing, but here's the one closest to the last output I sent you.

add response [Array[3], Array[2]]0: Array[3]0: 01: 22: 0length: 3__proto__: Array[0]1: Array[2]0: 01: Array[223]length: 2__proto__: Array[0]length: 2__proto__: Array[0]
background.js:138 not a 0-track add; retrying syncPlaylist [Array[3], Array[2]]

[simon-weber]

Got it. That looks like a successful response to me. Success is usually [[0, 1/2, 1/2], [<call-specific data>]]. In this case the server seems to be saying that it accepted the addition of 223 songs, but then they're not there when we check for them.

When I originally looked into this, the only difference between my request and Google's was that they invalidate a cache afterwards through a method I couldn't easily reproduce (it's not a simple api request, but a large jsproto sent over a previously-opened channel). It's reasonably likely that this is the problem; I was hoping we could get around it with the retry logic.

[simon-weber]

Ah, can you try this to export the console log when it happens? http://stackoverflow.com/a/31059700. I'm not sure it'll expand the objects, but just seeing the big picture may help me.

Drop it in a gist or on paste bin and link it, or feel free to email me directly if you don't feel comfortable sharing it publicly.

[johnrobertlawson]

Just emailed you @simon-weber .

[simon-weber]

Nice; thanks. I don't see anything weird going on, just Google not accepting the additions.

Some followup questions:

• at the time when the playlist is refreshing, approximately how many tracks does it have? If it's around 800, we might be running into the 1k limit during the intermediate state, which would explain why Google is rejecting the addition.
• does the number of tracks change while refreshing (maybe back and forth between the same numbers)? I don't expect this to be the case based on your logs.
• when it's refreshing, can you open the network panel in the devtools, wait until there are captured requests (I'm most interested in addtrackstoplaylist and loaduserplaylist, so be sure there are a few of each captured), then right click in an empty space and select "save as HAR with content". Email the result to me. Looking again at your addtrackstoplaylist response, I think there might be something there -- mine is always [[0, 1, 1], [...]] for a successful response, but if I'm reading yours correctly you're getting [[0, 2, 0], [...]], which I believe is an error response. I don't know exactly what the enums mean; I'll see if I can find out.

In the meantime, I'm going to push a release that will work better with dumping the logs to a file.

[simon-weber]

we might be running into the 1k limit during the intermediate state, which would explain why Google is rejecting the addition.

I don't believe this is an issue. I just ran the worst case - switching 1k tracks for 1k different tracks - and while it gave up on the sync initially, it converged on the next periodic sync.

[simon-weber]

@johnrobertlawson #35 (comment) described a new debugging idea that could be useful in this case as well.

[simon-weber]

The sentry support in 0.11.0 should also be helpful in debugging this, so be sure to upgrade.

[simon-weber]

The new Google Analytics setup should help me look into how useful retrying is (since that's what causes the refreshing in this situation). Here's an example from today that shows it might not be as useful as I thought:

In this example, the retries may have only saved 5% of syncs. I'll have more data in the coming weeks.

[johnrobertlawson]

Hi Simon, sorry I've been away. Got back using the extension today and the same problems - a lot of refreshing (not as much as before) and my autoplaylist isn't updating (but it is attempting the syncing, looking at the timestamp on the description). Which method do you recommend I take for bugfixing so I can send some stuff your way via email?

[simon-weber]

Can you send me the playlist id from the logs? That'll let me find the error in sentry.

You can get it in the logs from the "playlist has X entries. first 3: [..." line. Ideally, just send the one that's syncing many times, but if you can't tell, feel free to send me all of them.

[johnrobertlawson]

OK, I'll be emailing that shortly.

I'm also getting massive Google Play Music battery drain on my Nexus 6p despite not having used the app all day. I wonder if this syncing problem is also trying to sync playlist info to the phone, and causing wakelocks. I closed the G Music tab in Chrome (the computer remained on) but the idle battery drain continued overnight.

[simon-weber]

I wonder if this syncing problem is also trying to sync playlist info to the phone, and causing wakelocks

Ah, that sounds likely. Sorry about that! If you want to stop syncing temporarily, go to chrome://extensions then check disable and re-enable. That will stop syncing until you refresh a Google Music tab.

I suppose the good news is that most retries can be scrapped entirely for little cost: beyond the first, each retry only adds about 1% more successful syncs. Retry 5 is worse: just a .5% chance of a success. (It might even be that retries aren't doing this, and the real thing fixing it is time since the initial sync! Something to a/b test, potentially.)

I'll push an update tonight or tomorrow to scale back the syncs, which should help with both chrome refreshing and battery life. I'm planning to switch to a much less aggressive sync schedule once this is open to more people; right now, the idea is to make problems like these really obvious so we get a chance to fix them.

[simon-weber]

Don't worry about the playlist id -- I managed to find it in sentry.

I just pushed an experimental change that I'm hoping will affect this. Basically, I reverted the change from #10 (comment), with the added change to omit track type entirely when syncing. I'm hoping this allows us to use library ids across the board. This worked fine in my testing and I was able to recreate #10 originally, so at least I'm relatively confident I won't re-break AA track syncing.

[simon-weber]

I'm going to close this since it doesn't seem like anyone has seen this recently. Feel free to respond if it's still a problem and I'll reopen it.

[drew-wks]

I'm having the same problem as johnrobertlawson commented on Jan 28, 2016: a playlist refreshing every 10 sec and therefore scrolling back to the top. Can you help me?

[simon-weber]

Sure. Let's track it in a new issue, since this one's quite old.