1
8
Fork
You've already forked nup
0

Playback sometimes pauses between songs when using <audio> #92

Open
opened 2025年03月15日 14:19:28 +01:00 by derat · 30 comments
Owner
Copy link

I've noticed playback sometimes pause between songs. The UI doesn't have a spinner and just shows a play button, as if I'd manually paused. Pressing the play button resumes playback. It happens rarely -- I think I've only seen it three times across many hours of playback.

Here's all I see in the logs:

...
play-view.ts:1052 Preloading 5194444666044416 (https://...)
play-view.ts:970 Starting 5194444666044416 (https://...)
play-view.ts:1143 Scaling amplitude by 0.367 for track
play-view.ts:979 Playing
play-view.ts:320 Playback waiting

Looking at the audio element, paused is true and readyState is 4, i.e. HAVE_ENOUGH_DATA. played is empty and error is null. networkState is 1, i.e. NETWORK_IDLE.

Here's what chrome://media-internals/ says about it:

{
 "properties": {
 "render_id": 2571,
 "player_id": 36,
 "created": "2025年03月15日 12:53:55.792000 UTC",
 "origin_url": "...",
 "kFrameUrl": "...",
 "kFrameTitle": "TOBACCO - Sassy Ministries",
 "url": "https://...",
 "kTotalBytes": "0x86fde3",
 "kIsStreaming": false,
 "kIsSingleOrigin": true,
 "kIsRangeHeaderSupported": true,
 "kRendererName": "RendererImpl",
 "pipeline_state": "kSuspended",
 "info": "Selected FFmpegAudioDecoder for audio decoding, config: codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: false",
 "kAudioTracks": [
 {
 "bytes per channel": 2,
 "bytes per frame": 4,
 "channel layout": "STEREO",
 "channels": 2,
 "codec": "mp3",
 "codec delay": 0,
 "discard decoder delay": true,
 "encryption scheme": "Unencrypted",
 "has extra data": false,
 "profile": "unknown",
 "sample format": "Signed 16-bit planar",
 "samples per second": 44100,
 "seek preroll": "0us"
 }
 ],
 "kVideoTracks": [],
 "kMaxDuration": 262.870204,
 "kStartTime": 0,
 "kBitrate": 269237,
 "kIsAudioDecryptingDemuxerStream": false,
 "kAudioDecoderName": "FFmpegAudioDecoder",
 "kIsPlatformAudioDecoder": false,
 "duration": 262.870204,
 "pipeline_buffering_state": {
 "for_suspended_start": false,
 "state": "BUFFERING_HAVE_ENOUGH"
 },
 "event": "kSuspended",
 "seek_target": 0
 },
 "events": [
 {
 "time": 0,
 "key": "created",
 "value": "2025年03月15日 12:53:55.792000 UTC"
 },
 {
 "time": 0.29999999701976776,
 "key": "origin_url",
 "value": "..."
 },
 {
 "time": 0.31599999964237213,
 "key": "kFrameUrl",
 "value": "..."
 },
 {
 "time": 0.32499999552965164,
 "key": "kFrameTitle",
 "value": "TOBACCO - Sassy Ministries"
 },
 {
 "time": 0.4909999966621399,
 "key": "url",
 "value": "..."
 },
 {
 "time": 1745.0439999997616,
 "key": "kTotalBytes",
 "value": "0x86fde3"
 },
 {
 "time": 1745.070999994874,
 "key": "kIsStreaming",
 "value": false
 },
 {
 "time": 1745.0729999989271,
 "key": "kIsSingleOrigin",
 "value": true
 },
 {
 "time": 1745.0749999955297,
 "key": "kIsRangeHeaderSupported",
 "value": true
 },
 {
 "time": 1745.2309999987483,
 "key": "kRendererName",
 "value": "RendererImpl"
 },
 {
 "time": 1745.2739999964833,
 "key": "pipeline_state",
 "value": "kStarting"
 },
 {
 "time": 1837.4789999946952,
 "key": "info",
 "value": "FFmpegDemuxer: created audio stream, config codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: NONE, target_output_sample_format: Unknown sample format, has aac extra data: false"
 },
 {
 "time": 1837.5019999966025,
 "key": "kAudioTracks",
 "value": [
 {
 "bytes per channel": 2,
 "bytes per frame": 4,
 "channel layout": "STEREO",
 "channels": 2,
 "codec": "mp3",
 "codec delay": 0,
 "discard decoder delay": true,
 "encryption scheme": "Unencrypted",
 "has extra data": false,
 "profile": "unknown",
 "sample format": "Signed 16-bit planar",
 "samples per second": 44100,
 "seek preroll": "0us"
 }
 ]
 },
 {
 "time": 1837.5139999985695,
 "key": "kVideoTracks",
 "value": []
 },
 {
 "time": 1837.5239999964833,
 "key": "kMaxDuration",
 "value": 262.870204
 },
 {
 "time": 1837.5239999964833,
 "key": "kStartTime",
 "value": 0
 },
 {
 "time": 1837.5249999985099,
 "key": "kBitrate",
 "value": 269237
 },
 {
 "time": 1837.6079999953508,
 "key": "kIsAudioDecryptingDemuxerStream",
 "value": false
 },
 {
 "time": 1837.609999999404,
 "key": "kAudioDecoderName",
 "value": "FFmpegAudioDecoder"
 },
 {
 "time": 1837.6119999960065,
 "key": "kIsPlatformAudioDecoder",
 "value": false
 },
 {
 "time": 1837.625999994576,
 "key": "info",
 "value": "Selected FFmpegAudioDecoder for audio decoding, config: codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: false"
 },
 {
 "time": 1837.6699999943376,
 "key": "pipeline_state",
 "value": "kPlaying"
 },
 {
 "time": 1837.4930000007153,
 "key": "duration",
 "value": 262.870204
 },
 {
 "time": 1838.5590000003576,
 "key": "pipeline_buffering_state",
 "value": {
 "for_suspended_start": false,
 "state": "BUFFERING_HAVE_ENOUGH"
 }
 },
 {
 "time": 16839.33900000155,
 "key": "pipeline_state",
 "value": "kSuspending"
 },
 {
 "time": 16839.473999999464,
 "key": "pipeline_state",
 "value": "kSuspended"
 },
 {
 "time": 16839.586999997497,
 "key": "event",
 "value": "kSuspended"
 },
 {
 "time": 19932.27499999851,
 "key": "seek_target",
 "value": 0
 },
 {
 "time": 19932.35599999875,
 "key": "kRendererName",
 "value": "RendererImpl"
 },
 {
 "time": 19932.401000000536,
 "key": "seek_target",
 "value": 0
 },
 {
 "time": 19932.44999999553,
 "key": "pipeline_state",
 "value": "kResuming"
 },
 {
 "time": 19932.619999997318,
 "key": "info",
 "value": "Effective playback rate changed from 0 to 1"
 },
 {
 "time": 19940.26399999857,
 "key": "kIsAudioDecryptingDemuxerStream",
 "value": false
 },
 {
 "time": 19940.35000000149,
 "key": "kAudioDecoderName",
 "value": "FFmpegAudioDecoder"
 },
 {
 "time": 19940.353999994695,
 "key": "kIsPlatformAudioDecoder",
 "value": false
 },
 {
 "time": 19940.387999996543,
 "key": "info",
 "value": "Selected FFmpegAudioDecoder for audio decoding, config: codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: false"
 },
 {
 "time": 19940.601999998093,
 "key": "pipeline_state",
 "value": "kPlaying"
 },
 {
 "time": 19945.695999994874,
 "key": "pipeline_buffering_state",
 "value": {
 "for_suspended_start": false,
 "state": "BUFFERING_HAVE_ENOUGH"
 }
 },
 {
 "time": 19932.70300000161,
 "key": "event",
 "value": "kPlay"
 },
 {
 "time": 19949.803999997675,
 "key": "event",
 "value": "kPause"
 },
 {
 "time": 34951.24399999529,
 "key": "pipeline_state",
 "value": "kSuspending"
 },
 {
 "time": 34951.504000000656,
 "key": "pipeline_state",
 "value": "kSuspended"
 },
 {
 "time": 34951.63799999654,
 "key": "event",
 "value": "kSuspended"
 }
 ]
}

Comparing against the logs for the previous song, the kPause immediately after playing is where things go off the rails. Normally, there are no more events until FFmpegDemuxer: av_read_frame(): End of file and kEnded at the end of the file.

(Just to mention it, kFrameTitle weirdly always seems to refer to the previous song.)

I don't think I'd seen this prior to a week or two ago. I thought it was due to a flaky network connection then, but I saw it again just now without noticing any network issues, so now I think it might be a regression in Chrome. I was using a Bluetooth connection both times, but the timing between songs makes me think that it's not related to bogus media events. I'm currently on 133.0.6943.184.

I've noticed playback sometimes pause between songs. The UI doesn't have a spinner and just shows a play button, as if I'd manually paused. Pressing the play button resumes playback. It happens rarely -- I think I've only seen it three times across many hours of playback. Here's all I see in the logs: ``` ... play-view.ts:1052 Preloading 5194444666044416 (https://...) play-view.ts:970 Starting 5194444666044416 (https://...) play-view.ts:1143 Scaling amplitude by 0.367 for track play-view.ts:979 Playing play-view.ts:320 Playback waiting ``` Looking at the audio element, [paused](https://developer.mozilla.org/en-US/docs/Web/API/HTMLMediaElement/paused) is true and [readyState](https://developer.mozilla.org/en-US/docs/Web/API/HTMLMediaElement/readyState) is 4, i.e. `HAVE_ENOUGH_DATA`. [played](https://developer.mozilla.org/en-US/docs/Web/API/HTMLMediaElement/played) is empty and [error](https://developer.mozilla.org/en-US/docs/Web/API/HTMLMediaElement/error) is null. [networkState](https://developer.mozilla.org/en-US/docs/Web/API/HTMLMediaElement/networkState) is 1, i.e. `NETWORK_IDLE`. Here's what chrome://media-internals/ says about it: ```json { "properties": { "render_id": 2571, "player_id": 36, "created": "2025年03月15日 12:53:55.792000 UTC", "origin_url": "...", "kFrameUrl": "...", "kFrameTitle": "TOBACCO - Sassy Ministries", "url": "https://...", "kTotalBytes": "0x86fde3", "kIsStreaming": false, "kIsSingleOrigin": true, "kIsRangeHeaderSupported": true, "kRendererName": "RendererImpl", "pipeline_state": "kSuspended", "info": "Selected FFmpegAudioDecoder for audio decoding, config: codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: false", "kAudioTracks": [ { "bytes per channel": 2, "bytes per frame": 4, "channel layout": "STEREO", "channels": 2, "codec": "mp3", "codec delay": 0, "discard decoder delay": true, "encryption scheme": "Unencrypted", "has extra data": false, "profile": "unknown", "sample format": "Signed 16-bit planar", "samples per second": 44100, "seek preroll": "0us" } ], "kVideoTracks": [], "kMaxDuration": 262.870204, "kStartTime": 0, "kBitrate": 269237, "kIsAudioDecryptingDemuxerStream": false, "kAudioDecoderName": "FFmpegAudioDecoder", "kIsPlatformAudioDecoder": false, "duration": 262.870204, "pipeline_buffering_state": { "for_suspended_start": false, "state": "BUFFERING_HAVE_ENOUGH" }, "event": "kSuspended", "seek_target": 0 }, "events": [ { "time": 0, "key": "created", "value": "2025年03月15日 12:53:55.792000 UTC" }, { "time": 0.29999999701976776, "key": "origin_url", "value": "..." }, { "time": 0.31599999964237213, "key": "kFrameUrl", "value": "..." }, { "time": 0.32499999552965164, "key": "kFrameTitle", "value": "TOBACCO - Sassy Ministries" }, { "time": 0.4909999966621399, "key": "url", "value": "..." }, { "time": 1745.0439999997616, "key": "kTotalBytes", "value": "0x86fde3" }, { "time": 1745.070999994874, "key": "kIsStreaming", "value": false }, { "time": 1745.0729999989271, "key": "kIsSingleOrigin", "value": true }, { "time": 1745.0749999955297, "key": "kIsRangeHeaderSupported", "value": true }, { "time": 1745.2309999987483, "key": "kRendererName", "value": "RendererImpl" }, { "time": 1745.2739999964833, "key": "pipeline_state", "value": "kStarting" }, { "time": 1837.4789999946952, "key": "info", "value": "FFmpegDemuxer: created audio stream, config codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: NONE, target_output_sample_format: Unknown sample format, has aac extra data: false" }, { "time": 1837.5019999966025, "key": "kAudioTracks", "value": [ { "bytes per channel": 2, "bytes per frame": 4, "channel layout": "STEREO", "channels": 2, "codec": "mp3", "codec delay": 0, "discard decoder delay": true, "encryption scheme": "Unencrypted", "has extra data": false, "profile": "unknown", "sample format": "Signed 16-bit planar", "samples per second": 44100, "seek preroll": "0us" } ] }, { "time": 1837.5139999985695, "key": "kVideoTracks", "value": [] }, { "time": 1837.5239999964833, "key": "kMaxDuration", "value": 262.870204 }, { "time": 1837.5239999964833, "key": "kStartTime", "value": 0 }, { "time": 1837.5249999985099, "key": "kBitrate", "value": 269237 }, { "time": 1837.6079999953508, "key": "kIsAudioDecryptingDemuxerStream", "value": false }, { "time": 1837.609999999404, "key": "kAudioDecoderName", "value": "FFmpegAudioDecoder" }, { "time": 1837.6119999960065, "key": "kIsPlatformAudioDecoder", "value": false }, { "time": 1837.625999994576, "key": "info", "value": "Selected FFmpegAudioDecoder for audio decoding, config: codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: false" }, { "time": 1837.6699999943376, "key": "pipeline_state", "value": "kPlaying" }, { "time": 1837.4930000007153, "key": "duration", "value": 262.870204 }, { "time": 1838.5590000003576, "key": "pipeline_buffering_state", "value": { "for_suspended_start": false, "state": "BUFFERING_HAVE_ENOUGH" } }, { "time": 16839.33900000155, "key": "pipeline_state", "value": "kSuspending" }, { "time": 16839.473999999464, "key": "pipeline_state", "value": "kSuspended" }, { "time": 16839.586999997497, "key": "event", "value": "kSuspended" }, { "time": 19932.27499999851, "key": "seek_target", "value": 0 }, { "time": 19932.35599999875, "key": "kRendererName", "value": "RendererImpl" }, { "time": 19932.401000000536, "key": "seek_target", "value": 0 }, { "time": 19932.44999999553, "key": "pipeline_state", "value": "kResuming" }, { "time": 19932.619999997318, "key": "info", "value": "Effective playback rate changed from 0 to 1" }, { "time": 19940.26399999857, "key": "kIsAudioDecryptingDemuxerStream", "value": false }, { "time": 19940.35000000149, "key": "kAudioDecoderName", "value": "FFmpegAudioDecoder" }, { "time": 19940.353999994695, "key": "kIsPlatformAudioDecoder", "value": false }, { "time": 19940.387999996543, "key": "info", "value": "Selected FFmpegAudioDecoder for audio decoding, config: codec: mp3, profile: unknown, bytes_per_channel: 2, channel_layout: STEREO, channels: 2, samples_per_second: 44100, sample_format: Signed 16-bit planar, bytes_per_frame: 4, seek_preroll: 0us, codec_delay: 0, has extra data: false, encryption scheme: Unencrypted, discard decoder delay: true, target_output_channel_layout: STEREO, target_output_sample_format: Unknown sample format, has aac extra data: false" }, { "time": 19940.601999998093, "key": "pipeline_state", "value": "kPlaying" }, { "time": 19945.695999994874, "key": "pipeline_buffering_state", "value": { "for_suspended_start": false, "state": "BUFFERING_HAVE_ENOUGH" } }, { "time": 19932.70300000161, "key": "event", "value": "kPlay" }, { "time": 19949.803999997675, "key": "event", "value": "kPause" }, { "time": 34951.24399999529, "key": "pipeline_state", "value": "kSuspending" }, { "time": 34951.504000000656, "key": "pipeline_state", "value": "kSuspended" }, { "time": 34951.63799999654, "key": "event", "value": "kSuspended" } ] } ``` Comparing against the logs for the previous song, the `kPause` immediately after playing is where things go off the rails. Normally, there are no more events until `FFmpegDemuxer: av_read_frame(): End of file` and `kEnded` at the end of the file. (Just to mention it, `kFrameTitle` weirdly always seems to refer to the previous song.) I don't think I'd seen this prior to a week or two ago. I thought it was due to a flaky network connection then, but I saw it again just now without noticing any network issues, so now I think it might be a regression in Chrome. I was using a Bluetooth connection both times, but the timing between songs makes me think that it's not related to bogus media events. I'm currently on 133.0.6943.184.
Author
Owner
Copy link

The play-view component logs Pausing before it calls this.#audio.pause(), so it's not coming from there.

audio-wrapper calls this.#audio.pause() in a few places:

  • #onError pauses for !navigator.onLine, but it logs 'Offline; pausing before doing this.
  • pause sets a 30 ms timeout before pausing, but I don't think it's running since play-view appears to be is its only caller.
  • The src setter pauses before removing the underlying element's src attribute.

Some code in the setter looks a bit fishy to me:

 if (src && this.#preloadAudio.src !== src) {
 this.#audio.src = src;
 } else {
 this.#audio.pause();
 this.#audio.removeAttribute('src');
 if (this.#preloadAudio.src === src) {
 // Swap elements and update classes so tests know which one is in use.
 [this.#audio, this.#preloadAudio] = [this.#preloadAudio, this.#audio];
 this.#preloadAudio.classList.remove('active');
 this.#audio.classList.add('active');
 }
 }

The else block will also execute for e.g. src && this.#audio.src === src. Maybe that's okay, though -- this might legitimately happen if the same song should be played twice in a row, and I guess that stopping the current player and switching to the other one might be reasonable in that case. play-view only sets src from #playInternal, and only if this.#audio.src !== url, so it's not this... maybe? (Does playing the same song twice in a row even work? I should check it.)

Luckily/unluckily the problem seems to occur very infrequently, but if/when I see it again, I should probably add some spammy logging to audio-wrapper to make sure that it's not pausing.

The `play-view` component logs `Pausing` before it calls `this.#audio.pause()`, so it's not coming from there. `audio-wrapper` calls `this.#audio.pause()` in a few places: * `#onError` pauses for `!navigator.onLine`, but it logs `'Offline; pausing` before doing this. * `pause` sets a 30 ms timeout before pausing, but I don't think it's running since `play-view` appears to be is its only caller. * The `src` setter pauses before removing the underlying element's `src` attribute. Some code in the setter looks a bit fishy to me: ```ts if (src && this.#preloadAudio.src !== src) { this.#audio.src = src; } else { this.#audio.pause(); this.#audio.removeAttribute('src'); if (this.#preloadAudio.src === src) { // Swap elements and update classes so tests know which one is in use. [this.#audio, this.#preloadAudio] = [this.#preloadAudio, this.#audio]; this.#preloadAudio.classList.remove('active'); this.#audio.classList.add('active'); } } ``` The `else` block will also execute for e.g. `src && this.#audio.src === src`. Maybe that's okay, though -- this might legitimately happen if the same song should be played twice in a row, and I guess that stopping the current player and switching to the other one might be reasonable in that case. `play-view` only sets `src` from `#playInternal`, and only if `this.#audio.src !== url`, so it's not this... maybe? (Does playing the same song twice in a row even work? I should check it.) Luckily/unluckily the problem seems to occur very infrequently, but if/when I see it again, I should probably add some spammy logging to `audio-wrapper` to make sure that it's not pausing.
Author
Owner
Copy link

Playing the same 11-second song twice in a row works.

Playing the same 11-second song twice in a row works.
Author
Owner
Copy link

I was hoping that this was gone now, but I just saw it again.

I was hoping that this was gone now, but I just saw it again.
Author
Owner
Copy link

Just saw this again. Here are the verbose logs (1.mp3 was the previous song, 2.mp3 is the one that didn't play):

...
Starting 6378780306178048 1.mp3)
audio-wrapper.ts:184 Setting src to 1.mp3
audio-wrapper.ts:198 Pausing audio1 and removing src
audio-wrapper.ts:203 Setting audio2 to active
play-view.ts:1143 Scaling amplitude by 0.678 for track
play-view.ts:979 Playing
audio-wrapper.ts:245 Playing audio2
audio-wrapper.ts:128 audio2 is playing
play-view.ts:320 Playback waiting
updater.ts:108 Reporting play: ...
play-view.ts:1052 Preloading 5742344892579840 (2.mp3)
audio-wrapper.ts:298 Setting audio1 src to 2.mp3
audio-wrapper.ts:121 audio2 is paused
audio-wrapper.ts:184 Setting src to null
audio-wrapper.ts:198 Pausing audio2 and removing src
play-view.ts:970 Starting 5742344892579840 (2.mp3)
audio-wrapper.ts:184 Setting src to 2.mp3
audio-wrapper.ts:198 Pausing audio2 and removing src
audio-wrapper.ts:203 Setting audio1 to active
play-view.ts:1143 Scaling amplitude by 0.375 for track
play-view.ts:979 Playing
audio-wrapper.ts:245 Playing audio1
audio-wrapper.ts:128 audio1 is playing
play-view.ts:320 Playback waiting
audio-wrapper.ts:121 audio1 is paused
derat-music.appspot.com/:1 Uncaught (in promise) AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22

I don't think I'd seen that AbortError before, so I'm not sure this is the same thing. I didn't do anything to pause audio1 (and the app didn't log any requests), so I still suspect this is a Chrome or ChromeOS bug.

Per https://developer.chrome.com/blog/play-request-was-interrupted, I guess the next thing to do is check the promise returned by play().

Just saw this again. Here are the verbose logs (`1.mp3` was the previous song, `2.mp3` is the one that didn't play): ``` ... Starting 6378780306178048 1.mp3) audio-wrapper.ts:184 Setting src to 1.mp3 audio-wrapper.ts:198 Pausing audio1 and removing src audio-wrapper.ts:203 Setting audio2 to active play-view.ts:1143 Scaling amplitude by 0.678 for track play-view.ts:979 Playing audio-wrapper.ts:245 Playing audio2 audio-wrapper.ts:128 audio2 is playing play-view.ts:320 Playback waiting updater.ts:108 Reporting play: ... play-view.ts:1052 Preloading 5742344892579840 (2.mp3) audio-wrapper.ts:298 Setting audio1 src to 2.mp3 audio-wrapper.ts:121 audio2 is paused audio-wrapper.ts:184 Setting src to null audio-wrapper.ts:198 Pausing audio2 and removing src play-view.ts:970 Starting 5742344892579840 (2.mp3) audio-wrapper.ts:184 Setting src to 2.mp3 audio-wrapper.ts:198 Pausing audio2 and removing src audio-wrapper.ts:203 Setting audio1 to active play-view.ts:1143 Scaling amplitude by 0.375 for track play-view.ts:979 Playing audio-wrapper.ts:245 Playing audio1 audio-wrapper.ts:128 audio1 is playing play-view.ts:320 Playback waiting audio-wrapper.ts:121 audio1 is paused derat-music.appspot.com/:1 Uncaught (in promise) AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22 ``` I don't think I'd seen that `AbortError` before, so I'm not sure this is the same thing. I didn't do anything to pause `audio1` (and the app didn't log any requests), so I still suspect this is a Chrome or ChromeOS bug. Per https://developer.chrome.com/blog/play-request-was-interrupted, I guess the next thing to do is check the promise returned by `play()`.
Author
Owner
Copy link

I should also check the timestamps on the log messages the next time I see this. (The setting is annoyingly in the main DevTools settings instead of in the console settings.)

I should also check the timestamps on the log messages the next time I see this. (The setting is annoyingly in the main DevTools settings instead of in the console settings.)
Author
Owner
Copy link

play-view is already catching errors; it just doesn't swallow a pause was requested by the user:

 console.log('Playing'); 
 this.#audio.play().catch((e) => { 
 // play() actually returns a promise that is resolved after playback 
 // actually starts. If we change the <audio>'s src or call its pause() 
 // method while in the preparatory state, it complains. Ignore those
 // errors. 
 // https://developers.google.com/web/updates/2017/06/play-request-was-interrupted
 if ( 
 e.name === 'AbortError' && 
 (e.message.match(/interrupted by a new load request/) || 
 e.message.match(/interrupted by a call to pause/))
 ) { 
 return;
 }
 throw e;
 });
 }

I spent some time with https://cs.chromium.org/ but didn't figure out what's going on. I wasn't even using the Chromebook when I saw this happen (other than listening to music), so no idea why it thought I requested anything.

This might be a red herring since I didn't see the error before. I was thinking that maybe the requested by user string is new and the errors had been getting swallowed before, but it looks like it was added ~2022.

`play-view` is already catching errors; it just doesn't swallow `a pause was requested by the user`: ```ts console.log('Playing'); this.#audio.play().catch((e) => { // play() actually returns a promise that is resolved after playback // actually starts. If we change the <audio>'s src or call its pause() // method while in the preparatory state, it complains. Ignore those // errors. // https://developers.google.com/web/updates/2017/06/play-request-was-interrupted if ( e.name === 'AbortError' && (e.message.match(/interrupted by a new load request/) || e.message.match(/interrupted by a call to pause/)) ) { return; } throw e; }); } ``` I spent some time with https://cs.chromium.org/ but didn't figure out what's going on. I wasn't even using the Chromebook when I saw this happen (other than listening to music), so no idea why it thought I requested anything. This might be a red herring since I didn't see the error before. I was thinking that maybe the `requested by user` string is new and the errors had been getting swallowed before, but it looks like it was added ~2022.
Author
Owner
Copy link

Just saw this again. No error this time:

...
06:55:37.731 audio-wrapper.ts:122 audio1 is paused
06:55:37.733 audio-wrapper.ts:185 Setting src to null
06:55:37.733 audio-wrapper.ts:200 Pausing audio1 and removing src
06:55:37.733 play-view.ts:970 Starting 5365250163474432 (...)
06:55:37.733 audio-wrapper.ts:185 Setting src to ...
06:55:37.733 audio-wrapper.ts:200 Pausing audio1 and removing src
06:55:37.733 audio-wrapper.ts:204 Setting audio2 to active
06:55:37.734 play-view.ts:1143 Scaling amplitude by 0.338 for track
06:55:37.734 play-view.ts:979 Playing
06:55:37.734 audio-wrapper.ts:246 Playing audio2
06:55:37.744 audio-wrapper.ts:129 audio2 is playing
06:55:37.744 play-view.ts:320 Playback waiting
06:55:37.752 audio-wrapper.ts:122 audio2 is paused
Just saw this again. No error this time: ``` ... 06:55:37.731 audio-wrapper.ts:122 audio1 is paused 06:55:37.733 audio-wrapper.ts:185 Setting src to null 06:55:37.733 audio-wrapper.ts:200 Pausing audio1 and removing src 06:55:37.733 play-view.ts:970 Starting 5365250163474432 (...) 06:55:37.733 audio-wrapper.ts:185 Setting src to ... 06:55:37.733 audio-wrapper.ts:200 Pausing audio1 and removing src 06:55:37.733 audio-wrapper.ts:204 Setting audio2 to active 06:55:37.734 play-view.ts:1143 Scaling amplitude by 0.338 for track 06:55:37.734 play-view.ts:979 Playing 06:55:37.734 audio-wrapper.ts:246 Playing audio2 06:55:37.744 audio-wrapper.ts:129 audio2 is playing 06:55:37.744 play-view.ts:320 Playback waiting 06:55:37.752 audio-wrapper.ts:122 audio2 is paused ```
Author
Owner
Copy link

The ___ is playing message that I'm logging is misleading. It actually happens in response to the play event, which just indicates that the paused property changed from true to false. I'm not logging anything in response to the actual playing event that indicates that playback has started or restarted.

So yeah, I still don't know why the audio element is being paused, and suspect that it's a Chrome bug. I'm a bit afraid of trying to work around it by automatically playing again.

The `___ is playing` message that I'm logging is misleading. It actually happens in response to the [play event](https://developer.mozilla.org/en-US/docs/Web/API/HTMLMediaElement/play_event), which just indicates that the `paused` property changed from `true` to `false`. I'm not logging anything in response to the actual `playing` event that indicates that playback has started or restarted. So yeah, I still don't know why the audio element is being paused, and suspect that it's a Chrome bug. I'm a bit afraid of trying to work around it by automatically playing again.
Author
Owner
Copy link

Chrome actually emits a playing event and resolves the play() promise just before it pauses:

17:57:42.051 audio-wrapper.ts:219 Setting audio1 to active
17:57:42.052 play-view.ts:1145 Scaling amplitude by 0.288 for track
17:57:42.052 play-view.ts:980 Playing
17:57:42.052 audio-wrapper.ts:262 Playing audio1
17:57:42.057 audio-wrapper.ts:136 audio1 set to play
17:57:42.058 play-view.ts:321 Playback waiting
17:57:42.061 audio-wrapper.ts:144 audio1 is playing
17:57:42.061 play-view.ts:313 Playback started
17:57:42.061 play-view.ts:981 Play promise resolved
17:57:42.067 audio-wrapper.ts:125 audio1 is paused

There's still nothing useful in chrome://media-internals; just kPlay immediately followed by kPause:

00:00:19.757	pipeline_state	"kPlaying"
00:00:19.759	pipeline_buffering_state	{"for_suspended_start":false,"state":"BUFFERING_HAVE_ENOUGH"}
00:00:19.751	event	"kPlay"
00:00:19.765	event	"kPause"
00:00:34.766	pipeline_state	"kSuspending"
00:00:34.766	pipeline_state	"kSuspended"
00:00:34.767	event	"kSuspended"
Chrome actually emits a `playing` event and resolves the `play()` promise just before it pauses: ``` 17:57:42.051 audio-wrapper.ts:219 Setting audio1 to active 17:57:42.052 play-view.ts:1145 Scaling amplitude by 0.288 for track 17:57:42.052 play-view.ts:980 Playing 17:57:42.052 audio-wrapper.ts:262 Playing audio1 17:57:42.057 audio-wrapper.ts:136 audio1 set to play 17:57:42.058 play-view.ts:321 Playback waiting 17:57:42.061 audio-wrapper.ts:144 audio1 is playing 17:57:42.061 play-view.ts:313 Playback started 17:57:42.061 play-view.ts:981 Play promise resolved 17:57:42.067 audio-wrapper.ts:125 audio1 is paused ``` There's still nothing useful in chrome://media-internals; just `kPlay` immediately followed by `kPause`: ``` 00:00:19.757 pipeline_state "kPlaying" 00:00:19.759 pipeline_buffering_state {"for_suspended_start":false,"state":"BUFFERING_HAVE_ENOUGH"} 00:00:19.751 event "kPlay" 00:00:19.765 event "kPause" 00:00:34.766 pipeline_state "kSuspending" 00:00:34.766 pipeline_state "kSuspended" 00:00:34.767 event "kSuspended" ```
Author
Owner
Copy link

Gah, I saw this again even with my hacky workaround:

...
18:12:18.572 audio-wrapper.ts:222 Setting audio2 to active
18:12:18.573 play-view.ts:1145 Scaling amplitude by 0.588 for track
18:12:18.573 play-view.ts:980 Playing
18:12:18.573 audio-wrapper.ts:266 Playing audio2
18:12:18.590 audio-wrapper.ts:141 audio2 set to play
18:12:18.593 play-view.ts:321 Playback waiting
18:12:18.610 audio-wrapper.ts:148 audio2 is playing
18:12:18.615 play-view.ts:313 Playback started
18:12:18.615 play-view.ts:981 Play promise resolved
18:12:18.623 audio-wrapper.ts:129 audio2 is paused
18:12:18.623 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.623 audio-wrapper.ts:141 audio2 set to play
18:12:18.623 audio-wrapper.ts:148 audio2 is playing
18:12:18.623 play-view.ts:313 Playback started
18:12:18.635 audio-wrapper.ts:129 audio2 is paused
18:12:18.635 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.636 audio-wrapper.ts:141 audio2 set to play
18:12:18.636 audio-wrapper.ts:148 audio2 is playing
18:12:18.636 play-view.ts:313 Playback started
18:12:18.660 audio-wrapper.ts:129 audio2 is paused
18:12:18.660 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.660 audio-wrapper.ts:141 audio2 set to play
18:12:18.660 audio-wrapper.ts:148 audio2 is playing
18:12:18.660 play-view.ts:313 Playback started
18:12:18.675 audio-wrapper.ts:129 audio2 is paused
18:12:18.675 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.676 audio-wrapper.ts:141 audio2 set to play
18:12:18.676 audio-wrapper.ts:148 audio2 is playing
18:12:18.676 play-view.ts:313 Playback started
18:12:18.680 audio-wrapper.ts:129 audio2 is paused
18:12:18.680 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.681 audio-wrapper.ts:141 audio2 set to play
18:12:18.681 audio-wrapper.ts:148 audio2 is playing
18:12:18.681 play-view.ts:313 Playback started
18:12:18.686 audio-wrapper.ts:129 audio2 is paused
18:12:18.686 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.686 audio-wrapper.ts:141 audio2 set to play
18:12:18.686 audio-wrapper.ts:148 audio2 is playing
18:12:18.686 play-view.ts:313 Playback started
18:12:18.690 audio-wrapper.ts:129 audio2 is paused
18:12:18.690 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.690 audio-wrapper.ts:141 audio2 set to play
18:12:18.690 audio-wrapper.ts:148 audio2 is playing
18:12:18.690 play-view.ts:313 Playback started
18:12:18.695 audio-wrapper.ts:129 audio2 is paused
18:12:18.695 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.695 audio-wrapper.ts:141 audio2 set to play
18:12:18.695 audio-wrapper.ts:148 audio2 is playing
18:12:18.695 play-view.ts:313 Playback started
18:12:18.700 audio-wrapper.ts:129 audio2 is paused
18:12:18.701 audio-wrapper.ts:135 Playing audio2 again after unrequested pause
18:12:18.701 audio-wrapper.ts:141 audio2 set to play
18:12:18.701 audio-wrapper.ts:148 audio2 is playing
18:12:18.701 play-view.ts:313 Playback started
18:12:18.706 audio-wrapper.ts:129 audio2 is paused

Chrome kept pausing and I kept playing until currentTime reached 0.102697 and my code stopped unpausing. After I noticed it, I manually called play() via the JS console and playback proceeded normally, so maybe I should try adding a short delay before playing.

Gah, I saw this again even with my hacky workaround: ``` ... 18:12:18.572 audio-wrapper.ts:222 Setting audio2 to active 18:12:18.573 play-view.ts:1145 Scaling amplitude by 0.588 for track 18:12:18.573 play-view.ts:980 Playing 18:12:18.573 audio-wrapper.ts:266 Playing audio2 18:12:18.590 audio-wrapper.ts:141 audio2 set to play 18:12:18.593 play-view.ts:321 Playback waiting 18:12:18.610 audio-wrapper.ts:148 audio2 is playing 18:12:18.615 play-view.ts:313 Playback started 18:12:18.615 play-view.ts:981 Play promise resolved 18:12:18.623 audio-wrapper.ts:129 audio2 is paused 18:12:18.623 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.623 audio-wrapper.ts:141 audio2 set to play 18:12:18.623 audio-wrapper.ts:148 audio2 is playing 18:12:18.623 play-view.ts:313 Playback started 18:12:18.635 audio-wrapper.ts:129 audio2 is paused 18:12:18.635 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.636 audio-wrapper.ts:141 audio2 set to play 18:12:18.636 audio-wrapper.ts:148 audio2 is playing 18:12:18.636 play-view.ts:313 Playback started 18:12:18.660 audio-wrapper.ts:129 audio2 is paused 18:12:18.660 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.660 audio-wrapper.ts:141 audio2 set to play 18:12:18.660 audio-wrapper.ts:148 audio2 is playing 18:12:18.660 play-view.ts:313 Playback started 18:12:18.675 audio-wrapper.ts:129 audio2 is paused 18:12:18.675 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.676 audio-wrapper.ts:141 audio2 set to play 18:12:18.676 audio-wrapper.ts:148 audio2 is playing 18:12:18.676 play-view.ts:313 Playback started 18:12:18.680 audio-wrapper.ts:129 audio2 is paused 18:12:18.680 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.681 audio-wrapper.ts:141 audio2 set to play 18:12:18.681 audio-wrapper.ts:148 audio2 is playing 18:12:18.681 play-view.ts:313 Playback started 18:12:18.686 audio-wrapper.ts:129 audio2 is paused 18:12:18.686 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.686 audio-wrapper.ts:141 audio2 set to play 18:12:18.686 audio-wrapper.ts:148 audio2 is playing 18:12:18.686 play-view.ts:313 Playback started 18:12:18.690 audio-wrapper.ts:129 audio2 is paused 18:12:18.690 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.690 audio-wrapper.ts:141 audio2 set to play 18:12:18.690 audio-wrapper.ts:148 audio2 is playing 18:12:18.690 play-view.ts:313 Playback started 18:12:18.695 audio-wrapper.ts:129 audio2 is paused 18:12:18.695 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.695 audio-wrapper.ts:141 audio2 set to play 18:12:18.695 audio-wrapper.ts:148 audio2 is playing 18:12:18.695 play-view.ts:313 Playback started 18:12:18.700 audio-wrapper.ts:129 audio2 is paused 18:12:18.701 audio-wrapper.ts:135 Playing audio2 again after unrequested pause 18:12:18.701 audio-wrapper.ts:141 audio2 set to play 18:12:18.701 audio-wrapper.ts:148 audio2 is playing 18:12:18.701 play-view.ts:313 Playback started 18:12:18.706 audio-wrapper.ts:129 audio2 is paused ``` Chrome kept pausing and I kept playing until `currentTime` reached 0.102697 and my code stopped unpausing. After I noticed it, I manually called `play()` via the JS console and playback proceeded normally, so maybe I should try adding a short delay before playing.
Author
Owner
Copy link

I haven't seen this again since the latest change above, but I also haven't seen a log message in the console suggesting that the workaround was triggered. ̄\_(ツ)_/ ̄

I haven't seen this again since the latest change above, but I also haven't seen a log message in the console suggesting that the workaround was triggered. ` ̄\_(ツ)_/ ̄`
Author
Owner
Copy link

"Hooray", I just saw this again on Chrome 135.0.7049.120. My workaround was no match for Chrome, which just kept on repausing the song:

...
16:53:50.758 play-view.ts:1054 Preloading 6302260537589760 (...)
16:53:50.758 audio-wrapper.ts:336 Setting audio2 src to ...
16:54:10.558 audio-wrapper.ts:139 audio1 is paused
16:54:10.560 audio-wrapper.ts:216 Setting src to null
16:54:10.560 audio-wrapper.ts:231 Pausing audio1 and removing src
16:54:10.561 play-view.ts:971 Starting 6302260537589760 (...)
16:54:10.561 audio-wrapper.ts:216 Setting src to ... 
16:54:10.561 audio-wrapper.ts:231 Pausing audio1 and removing src 
16:54:10.561 audio-wrapper.ts:235 Setting audio2 to active
16:54:10.562 play-view.ts:1145 Scaling amplitude by 0.505 for track
16:54:10.563 play-view.ts:980 Playing 
16:54:10.563 audio-wrapper.ts:281 Playing audio2 
16:54:10.588 audio-wrapper.ts:153 audio2 set to play 
16:54:10.589 play-view.ts:321 Playback waiting 
16:54:10.603 audio-wrapper.ts:160 audio2 is playing
16:54:10.603 play-view.ts:313 Playback started
16:54:10.603 play-view.ts:981 Play promise resolved
16:54:10.656 audio-wrapper.ts:139 audio2 is paused 
16:54:10.656 audio-wrapper.ts:145 Got unrequested pause of audio2 at 0.063855 ms
16:54:11.657 audio-wrapper.ts:398 Playing audio2 again after unrequested pause
16:54:11.659 audio-wrapper.ts:153 audio2 set to play
16:54:11.659 audio-wrapper.ts:160 audio2 is playing
16:54:11.659 play-view.ts:313 Playback started 
16:54:11.688 audio-wrapper.ts:139 audio2 is paused
16:54:11.688 audio-wrapper.ts:145 Got unrequested pause of audio2 at 0.084235 ms
16:54:12.689 audio-wrapper.ts:398 Playing audio2 again after unrequested pause
16:54:12.700 audio-wrapper.ts:153 audio2 set to play
16:54:12.703 audio-wrapper.ts:160 audio2 is playing
16:54:12.703 play-view.ts:313 Playback started
16:54:12.706 audio-wrapper.ts:139 audio2 is paused
16:54:12.706 audio-wrapper.ts:145 Got unrequested pause of audio2 at 0.098685 ms
16:54:13.707 audio-wrapper.ts:398 Playing audio2 again after unrequested pause
16:54:13.708 audio-wrapper.ts:153 audio2 set to play
16:54:13.709 audio-wrapper.ts:160 audio2 is playing
16:54:13.709 play-view.ts:313 Playback started
16:54:13.736 audio-wrapper.ts:139 audio2 is paused
16:56:27.923 play-view.ts:980 Playing
16:56:27.924 audio-wrapper.ts:281 Playing audio2
16:56:27.979 audio-wrapper.ts:153 audio2 set to play
16:56:27.980 audio-wrapper.ts:160 audio2 is playing
16:56:27.980 play-view.ts:313 Playback started
16:56:27.981 play-view.ts:981 Play promise resolved

It worked as soon as I manually unpaused two minutes later, but I don't know whether it was the longer delay or the fact that this was a user action rather than a programmatic unpause that got it to work. I guess the next thing to try is to increase the max position for unpausing from 100 ms to something like 1 second.

"Hooray", I just saw this again on Chrome 135.0.7049.120. My workaround was no match for Chrome, which just kept on repausing the song: ``` ... 16:53:50.758 play-view.ts:1054 Preloading 6302260537589760 (...) 16:53:50.758 audio-wrapper.ts:336 Setting audio2 src to ... 16:54:10.558 audio-wrapper.ts:139 audio1 is paused 16:54:10.560 audio-wrapper.ts:216 Setting src to null 16:54:10.560 audio-wrapper.ts:231 Pausing audio1 and removing src 16:54:10.561 play-view.ts:971 Starting 6302260537589760 (...) 16:54:10.561 audio-wrapper.ts:216 Setting src to ... 16:54:10.561 audio-wrapper.ts:231 Pausing audio1 and removing src 16:54:10.561 audio-wrapper.ts:235 Setting audio2 to active 16:54:10.562 play-view.ts:1145 Scaling amplitude by 0.505 for track 16:54:10.563 play-view.ts:980 Playing 16:54:10.563 audio-wrapper.ts:281 Playing audio2 16:54:10.588 audio-wrapper.ts:153 audio2 set to play 16:54:10.589 play-view.ts:321 Playback waiting 16:54:10.603 audio-wrapper.ts:160 audio2 is playing 16:54:10.603 play-view.ts:313 Playback started 16:54:10.603 play-view.ts:981 Play promise resolved 16:54:10.656 audio-wrapper.ts:139 audio2 is paused 16:54:10.656 audio-wrapper.ts:145 Got unrequested pause of audio2 at 0.063855 ms 16:54:11.657 audio-wrapper.ts:398 Playing audio2 again after unrequested pause 16:54:11.659 audio-wrapper.ts:153 audio2 set to play 16:54:11.659 audio-wrapper.ts:160 audio2 is playing 16:54:11.659 play-view.ts:313 Playback started 16:54:11.688 audio-wrapper.ts:139 audio2 is paused 16:54:11.688 audio-wrapper.ts:145 Got unrequested pause of audio2 at 0.084235 ms 16:54:12.689 audio-wrapper.ts:398 Playing audio2 again after unrequested pause 16:54:12.700 audio-wrapper.ts:153 audio2 set to play 16:54:12.703 audio-wrapper.ts:160 audio2 is playing 16:54:12.703 play-view.ts:313 Playback started 16:54:12.706 audio-wrapper.ts:139 audio2 is paused 16:54:12.706 audio-wrapper.ts:145 Got unrequested pause of audio2 at 0.098685 ms 16:54:13.707 audio-wrapper.ts:398 Playing audio2 again after unrequested pause 16:54:13.708 audio-wrapper.ts:153 audio2 set to play 16:54:13.709 audio-wrapper.ts:160 audio2 is playing 16:54:13.709 play-view.ts:313 Playback started 16:54:13.736 audio-wrapper.ts:139 audio2 is paused 16:56:27.923 play-view.ts:980 Playing 16:56:27.924 audio-wrapper.ts:281 Playing audio2 16:56:27.979 audio-wrapper.ts:153 audio2 set to play 16:56:27.980 audio-wrapper.ts:160 audio2 is playing 16:56:27.980 play-view.ts:313 Playback started 16:56:27.981 play-view.ts:981 Play promise resolved ``` It worked as soon as I manually unpaused two minutes later, but I don't know whether it was the longer delay or the fact that this was a user action rather than a programmatic unpause that got it to work. I guess the next thing to try is to increase the max position for unpausing from 100 ms to something like 1 second.
Author
Owner
Copy link

I saw this again today, and this time the workaround eventually worked around it. While streaming to Bluetooth headphones, I noticed audio repeatedly starting and then immediately stopping at the beginning of a song. I went over to try to manually play to see if that'd help, but playback resumed while I was unlocking the screen.

16:41:01.500 Setting src to ...
16:41:01.500 Pausing audio2 and removing src
16:41:01.501 Setting audio1 to active
16:41:01.502 Scaling amplitude by 0.380 for album
16:41:01.502 Playing
16:41:01.502 Playing audio1
16:41:01.529 audio1 set to play
16:41:01.530 Playback waiting
16:41:01.581 audio1 is paused
16:41:01.581 Got unrequested pause of audio1 at 0.020317 ms
16:41:01.582 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22
16:41:01.592 derat-music.appspot.com/:1 Uncaught (in promise) 
16:41:02.582 Playing audio1 again after unrequested pause
16:41:02.585 audio1 set to play
16:41:02.585 audio1 is playing
16:41:02.586 Playback started
16:41:02.598 audio1 is paused
16:41:02.599 Got unrequested pause of audio1 at 0.043398 ms
16:41:03.600 Playing audio1 again after unrequested pause
16:41:03.601 audio1 set to play
16:41:03.602 audio1 is playing
16:41:03.602 Playback started
16:41:03.630 audio1 is paused
16:41:03.630 Got unrequested pause of audio1 at 0.058094 ms
16:41:04.630 Playing audio1 again after unrequested pause
16:41:04.631 audio1 set to play
16:41:04.631 audio1 is playing
16:41:04.642 Playback started
16:41:04.644 audio1 is paused
16:41:04.644 Got unrequested pause of audio1 at 0.082524 ms
16:41:05.644 Playing audio1 again after unrequested pause
...
16:41:24.006 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.359934 ms
16:41:25.006 audio-wrapper.ts:399 Playing audio1 again after unrequested pause
16:41:25.008 audio-wrapper.ts:154 audio1 set to play
16:41:25.008 audio-wrapper.ts:161 audio1 is playing
16:41:25.008 play-view.ts:313 Playback started
16:41:25.021 audio-wrapper.ts:140 audio1 is paused
16:41:25.021 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.377324 ms
16:41:26.021 audio-wrapper.ts:399 Playing audio1 again after unrequested pause
16:41:26.024 audio-wrapper.ts:154 audio1 set to play
16:41:26.024 audio-wrapper.ts:161 audio1 is playing
16:41:26.025 play-view.ts:313 Playback started
16:41:26.052 audio-wrapper.ts:140 audio1 is paused
16:41:26.052 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.400544 ms
16:41:27.053 audio-wrapper.ts:399 Playing audio1 again after unrequested pause
16:41:27.054 audio-wrapper.ts:154 audio1 set to play
16:41:27.055 audio-wrapper.ts:161 audio1 is playing
16:41:27.055 play-view.ts:313 Playback started
16:41:27.074 audio-wrapper.ts:140 audio1 is paused
16:41:27.075 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.409252 ms
16:41:28.075 audio-wrapper.ts:399 Playing audio1 again after unrequested pause
16:41:28.077 audio-wrapper.ts:154 audio1 set to play
16:41:28.077 audio-wrapper.ts:161 audio1 is playing
16:41:28.077 play-view.ts:313 Playback started
16:41:28.091 audio-wrapper.ts:140 audio1 is paused
16:41:28.091 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.438986 ms
16:41:29.091 audio-wrapper.ts:399 Playing audio1 again after unrequested pause
16:41:29.092 audio-wrapper.ts:154 audio1 set to play
16:41:29.092 audio-wrapper.ts:161 audio1 is playing
16:41:29.092 play-view.ts:313 Playback started

(I have no idea why the earlier messages don't have filenames and line numbers; maybe Chrome only saves them for recent messages.)

It looks like it took about 27.5 seconds before Chrome stopped pausing. I'll probably wait until this happens a few more times to see if it always takes that long to recover.

I guess that one other thing I could try is switching to the other <audio> element or resetting the current element's src when I see this.

I saw this again today, and this time the workaround eventually worked around it. While streaming to Bluetooth headphones, I noticed audio repeatedly starting and then immediately stopping at the beginning of a song. I went over to try to manually play to see if that'd help, but playback resumed while I was unlocking the screen. ``` 16:41:01.500 Setting src to ... 16:41:01.500 Pausing audio2 and removing src 16:41:01.501 Setting audio1 to active 16:41:01.502 Scaling amplitude by 0.380 for album 16:41:01.502 Playing 16:41:01.502 Playing audio1 16:41:01.529 audio1 set to play 16:41:01.530 Playback waiting 16:41:01.581 audio1 is paused 16:41:01.581 Got unrequested pause of audio1 at 0.020317 ms 16:41:01.582 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22 16:41:01.592 derat-music.appspot.com/:1 Uncaught (in promise) 16:41:02.582 Playing audio1 again after unrequested pause 16:41:02.585 audio1 set to play 16:41:02.585 audio1 is playing 16:41:02.586 Playback started 16:41:02.598 audio1 is paused 16:41:02.599 Got unrequested pause of audio1 at 0.043398 ms 16:41:03.600 Playing audio1 again after unrequested pause 16:41:03.601 audio1 set to play 16:41:03.602 audio1 is playing 16:41:03.602 Playback started 16:41:03.630 audio1 is paused 16:41:03.630 Got unrequested pause of audio1 at 0.058094 ms 16:41:04.630 Playing audio1 again after unrequested pause 16:41:04.631 audio1 set to play 16:41:04.631 audio1 is playing 16:41:04.642 Playback started 16:41:04.644 audio1 is paused 16:41:04.644 Got unrequested pause of audio1 at 0.082524 ms 16:41:05.644 Playing audio1 again after unrequested pause ... 16:41:24.006 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.359934 ms 16:41:25.006 audio-wrapper.ts:399 Playing audio1 again after unrequested pause 16:41:25.008 audio-wrapper.ts:154 audio1 set to play 16:41:25.008 audio-wrapper.ts:161 audio1 is playing 16:41:25.008 play-view.ts:313 Playback started 16:41:25.021 audio-wrapper.ts:140 audio1 is paused 16:41:25.021 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.377324 ms 16:41:26.021 audio-wrapper.ts:399 Playing audio1 again after unrequested pause 16:41:26.024 audio-wrapper.ts:154 audio1 set to play 16:41:26.024 audio-wrapper.ts:161 audio1 is playing 16:41:26.025 play-view.ts:313 Playback started 16:41:26.052 audio-wrapper.ts:140 audio1 is paused 16:41:26.052 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.400544 ms 16:41:27.053 audio-wrapper.ts:399 Playing audio1 again after unrequested pause 16:41:27.054 audio-wrapper.ts:154 audio1 set to play 16:41:27.055 audio-wrapper.ts:161 audio1 is playing 16:41:27.055 play-view.ts:313 Playback started 16:41:27.074 audio-wrapper.ts:140 audio1 is paused 16:41:27.075 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.409252 ms 16:41:28.075 audio-wrapper.ts:399 Playing audio1 again after unrequested pause 16:41:28.077 audio-wrapper.ts:154 audio1 set to play 16:41:28.077 audio-wrapper.ts:161 audio1 is playing 16:41:28.077 play-view.ts:313 Playback started 16:41:28.091 audio-wrapper.ts:140 audio1 is paused 16:41:28.091 audio-wrapper.ts:146 Got unrequested pause of audio1 at 0.438986 ms 16:41:29.091 audio-wrapper.ts:399 Playing audio1 again after unrequested pause 16:41:29.092 audio-wrapper.ts:154 audio1 set to play 16:41:29.092 audio-wrapper.ts:161 audio1 is playing 16:41:29.092 play-view.ts:313 Playback started ``` (I have no idea why the earlier messages don't have filenames and line numbers; maybe Chrome only saves them for recent messages.) It looks like it took about 27.5 seconds before Chrome stopped pausing. I'll probably wait until this happens a few more times to see if it always takes that long to recover. I guess that one other thing I could try is switching to the other `<audio>` element or resetting the current element's `src` when I see this.
Author
Owner
Copy link

I saw this twice in a single session yesterday. The workaround worked around it the first time, but not the second:

...
18:03:24.525 Starting 5754456129929216 (...)
18:03:24.525 Setting src to ...
18:03:24.525 Pausing audio1 and removing src
18:03:24.525 Setting audio2 to active
18:03:24.526 Scaling amplitude by 0.497 for track
18:03:24.526 Playing
18:03:24.526 Playing audio2
18:03:24.541 audio2 set to play
18:03:24.541 Playback waiting
18:03:24.568 audio2 is playing
18:03:24.568 Playback started
18:03:24.568 Play promise resolved
18:03:24.582 audio2 is paused
18:03:24.582 Got unrequested pause of audio2 at 0.01161 ms
18:03:25.584 Playing audio2 again after unrequested pause
18:03:25.585 audio2 set to play
18:03:25.586 audio2 is playing
18:03:25.586 Playback started
18:03:25.606 audio2 is paused
18:03:25.607 Got unrequested pause of audio2 at 0.043537 ms
18:03:26.607 Playing audio2 again after unrequested pause
...
18:03:44.919 Got unrequested pause of audio2 at 0.313469 ms
18:03:45.919 Playing audio2 again after unrequested pause
18:03:45.920 audio2 set to play
18:03:45.920 audio2 is playing
18:03:45.920 Playback started
18:03:45.935 audio2 is paused
18:03:45.935 Got unrequested pause of audio2 at 0.322177 ms
18:03:46.935 Playing audio2 again after unrequested pause
18:03:46.936 audio2 set to play
18:03:46.937 audio2 is playing
18:03:46.937 Playback started
18:05:25.683 Reporting play: played?songId=5754456129929216&startTime=2025年05月15日T22%3A03%3A24.525Z
...
18:26:25.329 Starting 5353611697586176 (...)
18:26:25.330 Setting src to ...
18:26:25.330 Pausing audio1 and removing src
18:26:25.330 Setting audio2 to active
18:26:25.331 Scaling amplitude by 2.084 for track
18:26:25.331 Playing
18:26:25.331 Playing audio2
18:26:25.358 audio2 set to play
18:26:25.358 Playback waiting
18:26:25.387 audio2 is playing
18:26:25.387 Playback started
18:26:25.387 Play promise resolved
18:26:25.402 audio2 is paused
18:26:25.403 Got unrequested pause of audio2 at 0.031927 ms
18:26:26.404 Playing audio2 again after unrequested pause
18:26:26.434 audio2 set to play
18:26:26.436 audio2 is playing
18:26:26.436 Playback started
18:26:26.464 audio2 is paused
18:26:26.464 Got unrequested pause of audio2 at 0.06966 ms
18:26:27.465 Playing audio2 again after unrequested pause
18:26:27.470 audio2 set to play
18:26:27.479 audio2 is playing
18:26:27.481 Playback started
18:26:27.485 audio2 is paused
18:26:27.486 Got unrequested pause of audio2 at 0.09288 ms
...
18:27:14.603 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.981043 ms
18:27:15.604 audio-wrapper.ts:399 Playing audio2 again after unrequested pause
18:27:15.615 audio-wrapper.ts:154 audio2 set to play
18:27:15.616 audio-wrapper.ts:161 audio2 is playing
18:27:15.617 play-view.ts:313 Playback started
18:27:15.628 audio-wrapper.ts:140 audio2 is paused
18:27:15.628 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.998809 ms
18:27:16.629 audio-wrapper.ts:399 Playing audio2 again after unrequested pause
18:27:16.636 audio-wrapper.ts:154 audio2 set to play
18:27:16.636 audio-wrapper.ts:161 audio2 is playing
18:27:16.637 play-view.ts:313 Playback started
18:27:16.654 audio-wrapper.ts:140 audio2 is paused
18:28:29.012 play-view.ts:980 Playing
18:28:29.012 audio-wrapper.ts:282 Playing audio2
18:28:29.014 audio-wrapper.ts:154 audio2 set to play
18:28:29.015 audio-wrapper.ts:161 audio2 is playing
18:28:29.015 play-view.ts:313 Playback started
18:28:29.015 play-view.ts:981 Play promise resolved
...

That makes me think it's not necessarily time-based. The first time, things started working again after about 22 seconds of fighting with Chrome, but the second time, it was still broken after 51 seconds, and it started working after I manually unpaused 12 seconds later.

I could try adding backing the backoff exponential, but I should also log some additional info about how much of the audio file is buffered to make sure this isn't an App Engine issue (although I'd hope that Chrome would just temporarily stop to buffer more data in that case instead of pausing).

I saw this twice in a single session yesterday. The workaround worked around it the first time, but not the second: ``` ... 18:03:24.525 Starting 5754456129929216 (...) 18:03:24.525 Setting src to ... 18:03:24.525 Pausing audio1 and removing src 18:03:24.525 Setting audio2 to active 18:03:24.526 Scaling amplitude by 0.497 for track 18:03:24.526 Playing 18:03:24.526 Playing audio2 18:03:24.541 audio2 set to play 18:03:24.541 Playback waiting 18:03:24.568 audio2 is playing 18:03:24.568 Playback started 18:03:24.568 Play promise resolved 18:03:24.582 audio2 is paused 18:03:24.582 Got unrequested pause of audio2 at 0.01161 ms 18:03:25.584 Playing audio2 again after unrequested pause 18:03:25.585 audio2 set to play 18:03:25.586 audio2 is playing 18:03:25.586 Playback started 18:03:25.606 audio2 is paused 18:03:25.607 Got unrequested pause of audio2 at 0.043537 ms 18:03:26.607 Playing audio2 again after unrequested pause ... 18:03:44.919 Got unrequested pause of audio2 at 0.313469 ms 18:03:45.919 Playing audio2 again after unrequested pause 18:03:45.920 audio2 set to play 18:03:45.920 audio2 is playing 18:03:45.920 Playback started 18:03:45.935 audio2 is paused 18:03:45.935 Got unrequested pause of audio2 at 0.322177 ms 18:03:46.935 Playing audio2 again after unrequested pause 18:03:46.936 audio2 set to play 18:03:46.937 audio2 is playing 18:03:46.937 Playback started 18:05:25.683 Reporting play: played?songId=5754456129929216&startTime=2025年05月15日T22%3A03%3A24.525Z ... 18:26:25.329 Starting 5353611697586176 (...) 18:26:25.330 Setting src to ... 18:26:25.330 Pausing audio1 and removing src 18:26:25.330 Setting audio2 to active 18:26:25.331 Scaling amplitude by 2.084 for track 18:26:25.331 Playing 18:26:25.331 Playing audio2 18:26:25.358 audio2 set to play 18:26:25.358 Playback waiting 18:26:25.387 audio2 is playing 18:26:25.387 Playback started 18:26:25.387 Play promise resolved 18:26:25.402 audio2 is paused 18:26:25.403 Got unrequested pause of audio2 at 0.031927 ms 18:26:26.404 Playing audio2 again after unrequested pause 18:26:26.434 audio2 set to play 18:26:26.436 audio2 is playing 18:26:26.436 Playback started 18:26:26.464 audio2 is paused 18:26:26.464 Got unrequested pause of audio2 at 0.06966 ms 18:26:27.465 Playing audio2 again after unrequested pause 18:26:27.470 audio2 set to play 18:26:27.479 audio2 is playing 18:26:27.481 Playback started 18:26:27.485 audio2 is paused 18:26:27.486 Got unrequested pause of audio2 at 0.09288 ms ... 18:27:14.603 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.981043 ms 18:27:15.604 audio-wrapper.ts:399 Playing audio2 again after unrequested pause 18:27:15.615 audio-wrapper.ts:154 audio2 set to play 18:27:15.616 audio-wrapper.ts:161 audio2 is playing 18:27:15.617 play-view.ts:313 Playback started 18:27:15.628 audio-wrapper.ts:140 audio2 is paused 18:27:15.628 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.998809 ms 18:27:16.629 audio-wrapper.ts:399 Playing audio2 again after unrequested pause 18:27:16.636 audio-wrapper.ts:154 audio2 set to play 18:27:16.636 audio-wrapper.ts:161 audio2 is playing 18:27:16.637 play-view.ts:313 Playback started 18:27:16.654 audio-wrapper.ts:140 audio2 is paused 18:28:29.012 play-view.ts:980 Playing 18:28:29.012 audio-wrapper.ts:282 Playing audio2 18:28:29.014 audio-wrapper.ts:154 audio2 set to play 18:28:29.015 audio-wrapper.ts:161 audio2 is playing 18:28:29.015 play-view.ts:313 Playback started 18:28:29.015 play-view.ts:981 Play promise resolved ... ``` That makes me think it's not necessarily time-based. The first time, things started working again after about 22 seconds of fighting with Chrome, but the second time, it was still broken after 51 seconds, and it started working after I manually unpaused 12 seconds later. I could try adding backing the backoff exponential, but I should also log some additional info about how much of the audio file is buffered to make sure this isn't an App Engine issue (although I'd hope that Chrome would just temporarily stop to buffer more data in that case instead of pausing).
Author
Owner
Copy link

This seems like it can also happen before the playing event is sent, resulting in the workaround never being triggered:

...
13:22:43.664 play-view.ts:971 Starting 6137867969495040 (...)
13:22:43.664 audio-wrapper.ts:217 Setting src to ...
13:22:43.664 audio-wrapper.ts:232 Pausing audio1 and removing src
13:22:43.664 audio-wrapper.ts:236 Setting audio2 to active
13:22:43.664 play-view.ts:1145 Scaling amplitude by 0.327 for track
13:22:43.665 play-view.ts:980 Playing
13:22:43.665 audio-wrapper.ts:282 Playing audio2
13:22:43.688 audio-wrapper.ts:154 audio2 set to play
13:22:43.689 play-view.ts:321 Playback waiting
13:22:43.710 audio-wrapper.ts:140 audio2 is paused
13:22:43.712 play-view.ts:982 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22

Chrome is lying; I didn't request a pause. I was in a different room using Bluetooth headphones. This only ever happens after a new song starts, which makes me strongly suspect that it's a Chrome bug and not caused by spurious Bluetooth media button events. (However, ChromeOS Bluetooth is still super-buggy, so I shouldn't discount the odds of it being to blame.)

This seems like it can also happen before the `playing` event is sent, resulting in the workaround never being triggered: ``` ... 13:22:43.664 play-view.ts:971 Starting 6137867969495040 (...) 13:22:43.664 audio-wrapper.ts:217 Setting src to ... 13:22:43.664 audio-wrapper.ts:232 Pausing audio1 and removing src 13:22:43.664 audio-wrapper.ts:236 Setting audio2 to active 13:22:43.664 play-view.ts:1145 Scaling amplitude by 0.327 for track 13:22:43.665 play-view.ts:980 Playing 13:22:43.665 audio-wrapper.ts:282 Playing audio2 13:22:43.688 audio-wrapper.ts:154 audio2 set to play 13:22:43.689 play-view.ts:321 Playback waiting 13:22:43.710 audio-wrapper.ts:140 audio2 is paused 13:22:43.712 play-view.ts:982 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22 ``` Chrome is lying; I didn't request a pause. I was in a different room using Bluetooth headphones. This only ever happens after a new song starts, which makes me strongly suspect that it's a Chrome bug and not caused by spurious Bluetooth media button events. (However, ChromeOS Bluetooth is still super-buggy, so I shouldn't discount the odds of it being to blame.)
Author
Owner
Copy link

I saw this again. The extra logging that I added showed that this isn't a buffering problem.

...
18:02:54.804 Starting 4632532934983680 (...)
18:02:54.804 Setting src to ...
18:02:54.804 Pausing audio1 and removing src
18:02:54.804 Setting audio2 to active
18:02:54.805 Scaling amplitude by 0.410 for track
18:02:54.806 Playing
18:02:54.806 Playing audio2
18:02:54.833 audio2 set to play
18:02:54.834 Playback waiting
18:02:54.852 audio2 is playing
18:02:54.852 Playback started
18:02:54.852 Play promise resolved
18:02:54.889 audio2 is paused
18:02:54.889 Got unrequested pause of audio2 at 0.031927 ms (readyState=4 networkState=1 buffered=[0.000-141.796])
18:02:56.891 Playing audio2 again after unrequested pause
18:02:56.891 audio2 set to play
18:02:56.892 audio2 is playing
18:02:56.892 Playback started
18:02:56.904 audio2 is paused
18:02:56.906 Got unrequested pause of audio2 at 0.043537 ms (readyState=4 networkState=1 buffered=[0.000-141.796])
18:02:58.907 Playing audio2 again after unrequested pause
18:02:58.909 audio2 set to play
18:02:58.910 audio2 is playing
18:02:58.910 Playback started
...
18:03:23.143 audio-wrapper.ts:140 audio2 is paused
18:03:23.143 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.267029 ms (readyState=4 networkState=1 buffered=[0.000-141.796])
18:03:25.143 audio-wrapper.ts:398 Playing audio2 again after unrequested pause
18:03:25.144 audio-wrapper.ts:154 audio2 set to play
18:03:25.145 audio-wrapper.ts:161 audio2 is playing
18:03:25.145 play-view.ts:315 Playback started
18:03:25.167 audio-wrapper.ts:140 audio2 is paused
18:03:25.168 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.285596 ms (readyState=4 networkState=1 buffered=[0.000-141.796])
18:03:27.169 audio-wrapper.ts:398 Playing audio2 again after unrequested pause
18:03:27.170 audio-wrapper.ts:154 audio2 set to play
18:03:27.172 audio-wrapper.ts:161 audio2 is playing
18:03:27.172 play-view.ts:315 Playback started
[playback continues uninterrupted]

I noticed that audio had stopped and unlocked the screen at 18:03:25.218. That aligns suspiciously well with when Chrome stopped pausing, but I'm not sure what I can do with that.

I saw this again. The extra logging that I added showed that this isn't a buffering problem. ``` ... 18:02:54.804 Starting 4632532934983680 (...) 18:02:54.804 Setting src to ... 18:02:54.804 Pausing audio1 and removing src 18:02:54.804 Setting audio2 to active 18:02:54.805 Scaling amplitude by 0.410 for track 18:02:54.806 Playing 18:02:54.806 Playing audio2 18:02:54.833 audio2 set to play 18:02:54.834 Playback waiting 18:02:54.852 audio2 is playing 18:02:54.852 Playback started 18:02:54.852 Play promise resolved 18:02:54.889 audio2 is paused 18:02:54.889 Got unrequested pause of audio2 at 0.031927 ms (readyState=4 networkState=1 buffered=[0.000-141.796]) 18:02:56.891 Playing audio2 again after unrequested pause 18:02:56.891 audio2 set to play 18:02:56.892 audio2 is playing 18:02:56.892 Playback started 18:02:56.904 audio2 is paused 18:02:56.906 Got unrequested pause of audio2 at 0.043537 ms (readyState=4 networkState=1 buffered=[0.000-141.796]) 18:02:58.907 Playing audio2 again after unrequested pause 18:02:58.909 audio2 set to play 18:02:58.910 audio2 is playing 18:02:58.910 Playback started ... 18:03:23.143 audio-wrapper.ts:140 audio2 is paused 18:03:23.143 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.267029 ms (readyState=4 networkState=1 buffered=[0.000-141.796]) 18:03:25.143 audio-wrapper.ts:398 Playing audio2 again after unrequested pause 18:03:25.144 audio-wrapper.ts:154 audio2 set to play 18:03:25.145 audio-wrapper.ts:161 audio2 is playing 18:03:25.145 play-view.ts:315 Playback started 18:03:25.167 audio-wrapper.ts:140 audio2 is paused 18:03:25.168 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.285596 ms (readyState=4 networkState=1 buffered=[0.000-141.796]) 18:03:27.169 audio-wrapper.ts:398 Playing audio2 again after unrequested pause 18:03:27.170 audio-wrapper.ts:154 audio2 set to play 18:03:27.172 audio-wrapper.ts:161 audio2 is playing 18:03:27.172 play-view.ts:315 Playback started [playback continues uninterrupted] ``` I noticed that audio had stopped and unlocked the screen at 18:03:25.218. That aligns suspiciously well with when Chrome stopped pausing, but I'm not sure what I can do with that.
Author
Owner
Copy link

I noticed this yet again while the screen was off. I tried unlocking but mistyped my password; it kept pausing. After I typed my password correctly, playback immediately resumed.

07:00:54.943 Starting 5491302519013376 (...)
07:00:54.944 Setting src to ...
07:00:54.944 Pausing audio1 and removing src
07:00:54.944 Setting audio2 to active
07:00:54.951 Scaling amplitude by 0.366 for track
07:00:54.951 Playing
07:00:54.952 Playing audio2
07:00:55.000 audio2 set to play
07:00:55.002 Playback waiting
07:00:55.020 audio2 is playing
07:00:55.020 Playback started
07:00:55.020 Play promise resolved
07:00:55.026 audio2 is paused
07:00:55.027 Got unrequested pause of audio2 at 0.06348 ms (readyState=4 networkState=1 buffered=[0.000-84.976])
...
07:01:31.430 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.36 ms (readyState=4 networkState=1 buffered=[0.000-84.976])
(anonymous) @ audio-wrapper.ts:146
07:01:33.431 audio-wrapper.ts:398 Playing audio2 again after unrequested pause
07:01:33.434 audio-wrapper.ts:154 audio2 set to play
07:01:33.435 audio-wrapper.ts:161 audio2 is playing
07:01:33.435 play-view.ts:315 Playback started

I noticed last time that there was some nonsense going on in /var/log/power_manager/powerd.LATEST, and that looks like it was the case again:

2025年05月30日T11:00:53.499046Z INFO powerd: [adaptive_charging_controller.cc(1046)] Policy update to enable Aaptive Charging
2025年05月30日T11:00:53.499101Z INFO powerd: [adaptive_charging_controller.cc(1751)] Stopping Charge Limit.
2025年05月30日T11:00:53.501650Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that suspend is ready
2025年05月30日T11:00:53.501927Z INFO powerd: [suspender.cc(187)] Ready for suspend (54067217) after 8h56m31s
2025年05月30日T11:00:53.502030Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that dark suspend is ready
2025年05月30日T11:00:53.502106Z INFO powerd: [daemon.cc(875)] Reading wakeup count from /sys/power/wakeup_count
2025年05月30日T11:00:53.502355Z INFO powerd: [daemon.cc(879)] Read wakeup count 10348
2025年05月30日T11:00:57.769748Z INFO powerd: [daemon.cc(1308)] On battery at 95% (displayed as 98%), 6.009/6.342Ah at 0.248A, 21h19m48s until empty (20h25m46s until shutdown)
2025年05月30日T11:00:59.120663Z INFO powerd: [daemon.cc(1801)] Received updated external policy: ac_dim=7m ac_screen_off=7m30s ac_lock=7m40s ac_idle_warn=0s ac_idle=8m30s battery_dim=5m battery_screen_off=5m30s battery_lock=5m40s battery_idle_warn=0s battery_idle=6m30s ac_idle=no-op battery_idle=no-op lid_closed=suspend system_wake_lock=1 use_audio=1 use_video=1 presentation_factor=1 user_activity_factor=1 wait_for_initial_user_activity=0 force_nonzero_brightness_for_user_activity=1 (Prefs, Playing audio)
2025年05月30日T11:00:59.120713Z INFO powerd: [state_controller.cc(1248)] Updated settings: dim=5m quick_dim=1m screen_off=5m30s lock=5m40s quick_lock=0s idle_warn=0s idle=6m30s (no-op) lid_closed=suspend use_audio=1 use_video=1 wake_locks=system
2025年05月30日T11:00:59.120734Z INFO powerd: [adaptive_charging_controller.cc(1046)] Policy update to enable Aaptive Charging
2025年05月30日T11:00:59.120740Z INFO powerd: [adaptive_charging_controller.cc(1751)] Stopping Charge Limit.
2025年05月30日T11:00:59.122928Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that suspend is ready
2025年05月30日T11:00:59.122990Z INFO powerd: [suspender.cc(187)] Ready for suspend (54067217) after 8h56m37s
2025年05月30日T11:00:59.123008Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that dark suspend is ready
2025年05月30日T11:00:59.123017Z INFO powerd: [daemon.cc(875)] Reading wakeup count from /sys/power/wakeup_count
2025年05月30日T11:00:59.123084Z INFO powerd: [daemon.cc(879)] Read wakeup count 10348
...

Why's powerd notifying about suspend being ready when the battery-idle action is no-op?

Maybe I should just make the web app hold a wake lock while it's playing audio...

I noticed this yet again while the screen was off. I tried unlocking but mistyped my password; it kept pausing. After I typed my password correctly, playback immediately resumed. ``` 07:00:54.943 Starting 5491302519013376 (...) 07:00:54.944 Setting src to ... 07:00:54.944 Pausing audio1 and removing src 07:00:54.944 Setting audio2 to active 07:00:54.951 Scaling amplitude by 0.366 for track 07:00:54.951 Playing 07:00:54.952 Playing audio2 07:00:55.000 audio2 set to play 07:00:55.002 Playback waiting 07:00:55.020 audio2 is playing 07:00:55.020 Playback started 07:00:55.020 Play promise resolved 07:00:55.026 audio2 is paused 07:00:55.027 Got unrequested pause of audio2 at 0.06348 ms (readyState=4 networkState=1 buffered=[0.000-84.976]) ... 07:01:31.430 audio-wrapper.ts:146 Got unrequested pause of audio2 at 0.36 ms (readyState=4 networkState=1 buffered=[0.000-84.976]) (anonymous) @ audio-wrapper.ts:146 07:01:33.431 audio-wrapper.ts:398 Playing audio2 again after unrequested pause 07:01:33.434 audio-wrapper.ts:154 audio2 set to play 07:01:33.435 audio-wrapper.ts:161 audio2 is playing 07:01:33.435 play-view.ts:315 Playback started ``` I noticed last time that there was some nonsense going on in `/var/log/power_manager/powerd.LATEST`, and that looks like it was the case again: ``` 2025年05月30日T11:00:53.499046Z INFO powerd: [adaptive_charging_controller.cc(1046)] Policy update to enable Aaptive Charging 2025年05月30日T11:00:53.499101Z INFO powerd: [adaptive_charging_controller.cc(1751)] Stopping Charge Limit. 2025年05月30日T11:00:53.501650Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that suspend is ready 2025年05月30日T11:00:53.501927Z INFO powerd: [suspender.cc(187)] Ready for suspend (54067217) after 8h56m31s 2025年05月30日T11:00:53.502030Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that dark suspend is ready 2025年05月30日T11:00:53.502106Z INFO powerd: [daemon.cc(875)] Reading wakeup count from /sys/power/wakeup_count 2025年05月30日T11:00:53.502355Z INFO powerd: [daemon.cc(879)] Read wakeup count 10348 2025年05月30日T11:00:57.769748Z INFO powerd: [daemon.cc(1308)] On battery at 95% (displayed as 98%), 6.009/6.342Ah at 0.248A, 21h19m48s until empty (20h25m46s until shutdown) 2025年05月30日T11:00:59.120663Z INFO powerd: [daemon.cc(1801)] Received updated external policy: ac_dim=7m ac_screen_off=7m30s ac_lock=7m40s ac_idle_warn=0s ac_idle=8m30s battery_dim=5m battery_screen_off=5m30s battery_lock=5m40s battery_idle_warn=0s battery_idle=6m30s ac_idle=no-op battery_idle=no-op lid_closed=suspend system_wake_lock=1 use_audio=1 use_video=1 presentation_factor=1 user_activity_factor=1 wait_for_initial_user_activity=0 force_nonzero_brightness_for_user_activity=1 (Prefs, Playing audio) 2025年05月30日T11:00:59.120713Z INFO powerd: [state_controller.cc(1248)] Updated settings: dim=5m quick_dim=1m screen_off=5m30s lock=5m40s quick_lock=0s idle_warn=0s idle=6m30s (no-op) lid_closed=suspend use_audio=1 use_video=1 wake_locks=system 2025年05月30日T11:00:59.120734Z INFO powerd: [adaptive_charging_controller.cc(1046)] Policy update to enable Aaptive Charging 2025年05月30日T11:00:59.120740Z INFO powerd: [adaptive_charging_controller.cc(1751)] Stopping Charge Limit. 2025年05月30日T11:00:59.122928Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that suspend is ready 2025年05月30日T11:00:59.122990Z INFO powerd: [suspender.cc(187)] Ready for suspend (54067217) after 8h56m37s 2025年05月30日T11:00:59.123008Z INFO powerd: [suspend_delay_controller.cc(319)] Notifying observers that dark suspend is ready 2025年05月30日T11:00:59.123017Z INFO powerd: [daemon.cc(875)] Reading wakeup count from /sys/power/wakeup_count 2025年05月30日T11:00:59.123084Z INFO powerd: [daemon.cc(879)] Read wakeup count 10348 ... ``` Why's powerd notifying about suspend being ready when the battery-idle action is `no-op`? Maybe I should just make the web app hold a wake lock while it's playing audio...
Author
Owner
Copy link

Sigh. The Wake Lock API 20171214 spec had a system type for WakeLockType, but they removed it in 20200929. Chrome doesn't support system.

Sigh. The Wake Lock API [20171214](https://www.w3.org/TR/2017/CR-wake-lock-20171214/#the-wakelocktype-enum) spec had a `system` type for `WakeLockType`, but they removed it in [20200929](https://www.w3.org/TR/2020/WD-screen-wake-lock-20200929/#the-wakelocktype-enum). Chrome doesn't support `system`.
Author
Owner
Copy link

I spent some time making audio-wrapper start playing an empty audio file near the end of each song and pause it after the next song begins, but I don't know if it'd help. I see Audio activity ongoing in the powerd log but nothing indicating that it stopped, so even though it looks like there are power management bugs, I'm not convinced that they're causing this. I think it's still most likely that this is a regression in Chrome's autoplay policy (maybe since I'm swapping between two <audio> elements?), but I have no idea if making playback continuous by introducing a third element would help with that.

I spent some time making `audio-wrapper` start playing an empty audio file near the end of each song and pause it after the next song begins, but I don't know if it'd help. I see `Audio activity ongoing` in the powerd log but nothing indicating that it stopped, so even though it looks like there are power management bugs, I'm not convinced that they're causing this. I think it's still most likely that this is a regression in [Chrome's autoplay policy](https://developer.chrome.com/blog/autoplay) (maybe since I'm swapping between two `<audio>` elements?), but I have no idea if making playback continuous by introducing a third element would help with that.
Author
Owner
Copy link

I think that this is the timeline, after piecing together the various logs using lnav:

10:55:38.098667 powerd turns screen off for inactivity 
10:55:48.097486 powerd locks screen for inactivity 
10:58:45.374287 powerd says audio activity is ongoing 
10:59:13.802475 powerd says chrome holds audio wake lock 
11:00:53.498618 powerd says chrome dropped audio wake lock 
11:00:54.952000 nup starts new song 
11:00:54.971928 chrome reports d-bus error 
11:00:55.027000 nup reports unrequested pause (many unpause attempts omitted) 
11:00:59.120663 powerd says chrome holds audio wake lock 
11:01:05.398756 powerd says chrome dropped audio wake lock 
11:01:07.209649 powerd says chrome holds audio wake lock 
11:01:26.571375 powerd receives user activity, turns screen on 
11:01:30.402560 chrome reports start of auth attempt 
11:01:31.430000 nup reports unrequested pause 
11:01:32.563520 chrome reports start of auth attempt 
11:01:32.602619 chrome hides lock screen 
11:01:33.431000 nup tries to play audio again (and succeeds)

There are actually a bunch of weird inappropriate suspend attempts from powerd in the logs, so I think that's a red herring and probably not related to this. My best guess is still that this is a Chrome bug.

I think that this is the timeline, after piecing together the various logs using `lnav`: ``` 10:55:38.098667 powerd turns screen off for inactivity 10:55:48.097486 powerd locks screen for inactivity 10:58:45.374287 powerd says audio activity is ongoing 10:59:13.802475 powerd says chrome holds audio wake lock 11:00:53.498618 powerd says chrome dropped audio wake lock 11:00:54.952000 nup starts new song 11:00:54.971928 chrome reports d-bus error 11:00:55.027000 nup reports unrequested pause (many unpause attempts omitted) 11:00:59.120663 powerd says chrome holds audio wake lock 11:01:05.398756 powerd says chrome dropped audio wake lock 11:01:07.209649 powerd says chrome holds audio wake lock 11:01:26.571375 powerd receives user activity, turns screen on 11:01:30.402560 chrome reports start of auth attempt 11:01:31.430000 nup reports unrequested pause 11:01:32.563520 chrome reports start of auth attempt 11:01:32.602619 chrome hides lock screen 11:01:33.431000 nup tries to play audio again (and succeeds) ``` There are actually a bunch of weird inappropriate suspend attempts from powerd in the logs, so I think that's a red herring and probably not related to this. My best guess is still that this is a Chrome bug.
Author
Owner
Copy link

This continues to happen with annoying frequency. I'm starting to suspect that it only happens when I've been idle long enough for the screen to lock and turn off (not sure if turning off is required). Sometimes the play promise is rejected (maybe based on how quickly the auto-pause happens)?

...
06:22:38.063 play-view.ts:991 Playing
06:22:38.064 audio-wrapper.ts:281 Playing audio2
06:22:38.091 audio-wrapper.ts:154 audio2 set to play
06:22:38.091 play-view.ts:323 Playback waiting
06:22:38.107 audio-wrapper.ts:140 audio2 is paused
06:22:38.110 play-view.ts:993 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22

I wasn't able to trigger it (only tried once) by manually locking the screen and letting it turn off before the end of a song.

This continues to happen with annoying frequency. I'm starting to suspect that it only happens when I've been idle long enough for the screen to lock and turn off (not sure if turning off is required). Sometimes the play promise is rejected (maybe based on how quickly the auto-pause happens)? ``` ... 06:22:38.063 play-view.ts:991 Playing 06:22:38.064 audio-wrapper.ts:281 Playing audio2 06:22:38.091 audio-wrapper.ts:154 audio2 set to play 06:22:38.091 play-view.ts:323 Playback waiting 06:22:38.107 audio-wrapper.ts:140 audio2 is paused 06:22:38.110 play-view.ts:993 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22 ``` I wasn't able to trigger it (only tried once) by manually locking the screen and letting it turn off before the end of a song.
Author
Owner
Copy link

There's a TODO in the Chromium source suggesting that this message is sometimes used when the pause wasn't actually requested by the user:

 // The Browser process has requested to pause the media.
 // TODO(crbug.com/40623496): Make sure that this is only used when there is
 // a user gesture.
 kPauseRequestedByUser,

The referenced bug was filed in 2019 and hasn't been touched since then: https://crbug.com/40623496

Looking at the code, this is coming over IPC, so I have no idea how to figure out what actually changed to trigger it. Maybe there was a Chrome OS change to try to prevent new things from playing when the screen is locked?

There's [a TODO in the Chromium source](https://source.chromium.org/chromium/chromium/src/+/main:third_party/blink/public/platform/web_media_player.h;drc=eac3931ab001973d939a36f424027b3e5f81102a;l=158) suggesting that this message is sometimes used when the pause wasn't actually requested by the user: ```cpp // The Browser process has requested to pause the media. // TODO(crbug.com/40623496): Make sure that this is only used when there is // a user gesture. kPauseRequestedByUser, ``` The referenced bug was filed in 2019 and hasn't been touched since then: https://crbug.com/40623496 Looking at the code, this is coming over IPC, so I have no idea how to figure out what actually changed to trigger it. Maybe there was a Chrome OS change to try to prevent new things from playing when the screen is locked?
Author
Owner
Copy link

Haven't found any relevant bugs yet. https://issues.chromium.org/issues/393418383 mentions the media control panel disappearing on the lock screen, which is another thing I've noticed. The claim there is that it's only supposed to be hidden if the system has suspended, but I'm pretty sure from the logs that that didn't happen (despite all the powerd garbage about notifying observers that the system is ready to suspend).

Haven't found any relevant bugs yet. https://issues.chromium.org/issues/393418383 mentions the media control panel disappearing on the lock screen, which is another thing I've noticed. The claim there is that it's only supposed to be hidden if the system has suspended, but I'm pretty sure from the logs that that didn't happen (despite all the powerd garbage about notifying observers that the system is ready to suspend).
Author
Owner
Copy link

This is still very inconsistent.

  1. The app cycled through a few songs without problems after the screen had locked and turned off.
  2. I pressed the pause button on Bluetooth headphones, which paused and turned the screen on, displaying the lock screen with media controls for the current song.
  3. I pressed the pause button again a few minutes later to unpause. Playback contained, with the lock screen and media controls still shown.
  4. At the end of the song, playback automatically paused while the screen was still on. The lock screen was still displayed, but the media controls disappeared immediately when playback was paused.
06:11:06.911 audio-wrapper.ts:267 Playing audio1
06:11:06.955 audio-wrapper.ts:143 audio1 set to play
06:11:06.955 play-view.ts:323 Playback waiting
06:11:06.962 audio-wrapper.ts:129 audio1 is paused
06:11:06.963 audio-wrapper.ts:136 Got unrequested pause of audio1 at 0 ms (context=running readyState=1 networkState=1 buffered=[0.000-83.054])
06:11:06.965 play-view.ts:993 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22

That lends more support to this being caused by Chrome OS screen lock.

This is still very inconsistent. 1. The app cycled through a few songs without problems after the screen had locked and turned off. 2. I pressed the pause button on Bluetooth headphones, which paused and turned the screen on, displaying the lock screen with media controls for the current song. 3. I pressed the pause button again a few minutes later to unpause. Playback contained, with the lock screen and media controls still shown. 4. At the end of the song, playback automatically paused while the screen was still on. The lock screen was still displayed, but the media controls disappeared immediately when playback was paused. ``` 06:11:06.911 audio-wrapper.ts:267 Playing audio1 06:11:06.955 audio-wrapper.ts:143 audio1 set to play 06:11:06.955 play-view.ts:323 Playback waiting 06:11:06.962 audio-wrapper.ts:129 audio1 is paused 06:11:06.963 audio-wrapper.ts:136 Got unrequested pause of audio1 at 0 ms (context=running readyState=1 networkState=1 buffered=[0.000-83.054]) 06:11:06.965 play-view.ts:993 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22 ``` That lends more support to this being caused by Chrome OS screen lock.
Author
Owner
Copy link

Still happens on a different Chromebook (136.0.7103.158) using a different Bluetooth speaker:

audio-wrapper.ts:136 Got unrequested pause of audio1 at 0.031927 ms (context=running readyState=4 networkState=1 buffered=[0.000-69.721])
Still happens on a different Chromebook (136.0.7103.158) using a different Bluetooth speaker: ``` audio-wrapper.ts:136 Got unrequested pause of audio1 at 0.031927 ms (context=running readyState=4 networkState=1 buffered=[0.000-69.721]) ```
Author
Owner
Copy link

My current thinking is that I'll probably add a hack where play-view (or maybe even audio-wrapper?) holds a screen wake lock while playing audio to keep Chrome OS from locking the screen. I can manually reduce the backlight brightness to 0 if I want to conserve battery.

My current thinking is that I'll probably add a hack where `play-view` (or maybe even `audio-wrapper`?) holds a screen wake lock while playing audio to keep Chrome OS from locking the screen. I can manually reduce the backlight brightness to 0 if I want to conserve battery.
Author
Owner
Copy link

Sigh, even this workaround doesn't work consistently. It looks like the wake lock is automatically released when I switch tabs. From https://developer.chrome.com/docs/capabilities/web-apis/wake-lock:

When you play with the screen wake lock demo, you'll notice that screen wake locks are sensitive to page visibility. This means that the screen wake lock will automatically be released when you minimize a tab or window, or switch away from a tab or window where a screen wake lock is active.

To reacquire the screen wake lock, listen for the visibilitychange event and request a new screen wake lock when they occur:

const handleVisibilityChange = async () => {
 if (wakeLock !== null && document.visibilityState === 'visible') {
 await requestWakeLock();
 }
};
document.addEventListener('visibilitychange', handleVisibilityChange);
Sigh, even this workaround doesn't work consistently. It looks like the wake lock is automatically released when I switch tabs. From https://developer.chrome.com/docs/capabilities/web-apis/wake-lock: > When you play with the screen wake lock demo, you'll notice that screen wake locks are sensitive to page visibility. This means that the screen wake lock will automatically be released when you minimize a tab or window, or switch away from a tab or window where a screen wake lock is active. > > To reacquire the screen wake lock, listen for the visibilitychange event and request a new screen wake lock when they occur: > > > ```js > const handleVisibilityChange = async () => { > if (wakeLock !== null && document.visibilityState === 'visible') { > await requestWakeLock(); > } > }; > > document.addEventListener('visibilitychange', handleVisibilityChange); > ```
Author
Owner
Copy link

I think the latest workaround works as long as I keep the tab focused.

If not:

...
14:16:07.350 audio-wrapper.ts:267 Playing audio1
14:16:07.379 play-view.ts:1132 Failed acquiring wake lock: NotAllowedError: Failed to execute 'request' on 'WakeLock': The requesting page is not visible
(anonymous) @ play-view.ts:1132
14:16:07.393 audio-wrapper.ts:143 audio1 set to play
14:16:07.394 play-view.ts:1132 Failed acquiring wake lock: NotAllowedError: Failed to execute 'request' on 'WakeLock': The requesting page is not visible
(anonymous) @ play-view.ts:1132
14:16:07.394 play-view.ts:338 Playback waiting
14:16:07.405 audio-wrapper.ts:129 audio1 is paused
14:16:07.406 audio-wrapper.ts:136 Got unrequested pause of audio1 at 0 ms (context=running readyState=1 networkState=1 buffered=[0.000-99.759])
(anonymous) @ audio-wrapper.ts:136
14:16:07.406 play-view.ts:1132 Failed acquiring wake lock: NotAllowedError: Failed to execute 'request' on 'WakeLock': The requesting page is not visible
(anonymous) @ play-view.ts:1132
14:16:07.406 play-view.ts:1014 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22
14:17:58.815 play-view.ts:1125 Acquired wake lock
14:17:58.815 play-view.ts:1125 Acquired wake lock
14:18:13.164 play-view.ts:1012 Playing
14:18:13.165 audio-wrapper.ts:267 Playing audio1

I should update the code to not try over and over again.

I think the latest workaround works as long as I keep the tab focused. If not: ``` ... 14:16:07.350 audio-wrapper.ts:267 Playing audio1 14:16:07.379 play-view.ts:1132 Failed acquiring wake lock: NotAllowedError: Failed to execute 'request' on 'WakeLock': The requesting page is not visible (anonymous) @ play-view.ts:1132 14:16:07.393 audio-wrapper.ts:143 audio1 set to play 14:16:07.394 play-view.ts:1132 Failed acquiring wake lock: NotAllowedError: Failed to execute 'request' on 'WakeLock': The requesting page is not visible (anonymous) @ play-view.ts:1132 14:16:07.394 play-view.ts:338 Playback waiting 14:16:07.405 audio-wrapper.ts:129 audio1 is paused 14:16:07.406 audio-wrapper.ts:136 Got unrequested pause of audio1 at 0 ms (context=running readyState=1 networkState=1 buffered=[0.000-99.759]) (anonymous) @ audio-wrapper.ts:136 14:16:07.406 play-view.ts:1132 Failed acquiring wake lock: NotAllowedError: Failed to execute 'request' on 'WakeLock': The requesting page is not visible (anonymous) @ play-view.ts:1132 14:16:07.406 play-view.ts:1014 Play promise rejected: AbortError: The play() request was interrupted because a pause was requested by the user. https://goo.gl/LdLk22 14:17:58.815 play-view.ts:1125 Acquired wake lock 14:17:58.815 play-view.ts:1125 Acquired wake lock 14:18:13.164 play-view.ts:1012 Playing 14:18:13.165 audio-wrapper.ts:267 Playing audio1 ``` I should update the code to not try over and over again.
Author
Owner
Copy link

I think that the wake lock workaround works now (as long as I remember to keep the tab visible when I step away). There's probably nothing more that I can do here.

I think that the wake lock workaround works now (as long as I remember to keep the tab visible when I step away). There's probably nothing more that I can do here.
derat changed title from (削除) Playback sometimes pauses between songs (削除ここまで) to Playback sometimes pauses between songs when using <audio> 2025年12月14日 02:42:01 +01:00
Author
Owner
Copy link

This is still present in ChromeOS 147.0.7727.142.

This is still present in ChromeOS 147.0.7727.142.
Sign in to join this conversation.
No Branch/Tag specified
main
headless
picture
datastore
No results found.
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
derat/nup#92
Reference in a new issue
derat/nup
No description provided.
Delete branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?