No Buffering state ever received, only Connecting and Paused

[austinried]

Describe the Bug Using v2.2.0-rc3 I have noticed I never receive the Buffering state anymore. I get a Connecting state when the queue first starts playing, and then a quick Paused state when skipping tracks/seeking within a track. Here's an example log of states:

 LOG  None
 LOG  Connecting
 LOG  Playing
 LOG  Paused  <--- Skip to next track
 LOG  Playing
 LOG  Paused  <--- Seek within track
 LOG  Playing

Steps To Reproduce Load up a queue of URLs, watch state transitions as you skip/seek tracks.

Environment Info: Paste the results of npx react-native info

System:
    OS: Linux 5.4 Ubuntu 20.04.4 LTS (Focal Fossa)
    CPU: (8) x64 Intel(R) Core(TM) i7-8650U CPU @ 1.90GHz
    Memory: 158.45 MB / 15.39 GB
    Shell: 5.0.17 - /bin/bash
  Binaries:
    Node: 14.19.1 - /tmp/yarn--1650003558066-0.14211410378890887/node
    Yarn: 1.22.18 - /tmp/yarn--1650003558066-0.14211410378890887/yarn
    npm: 6.14.16 - ~/.nvm/versions/node/v14.19.1/bin/npm
    Watchman: 4.9.0 - /usr/bin/watchman
  SDKs:
    Android SDK:
      Android NDK: 22.1.7171670
  IDEs:
    Android Studio: Not Found
  Languages:
    Java: 11.0.12 - /home/austin/.sdkman/candidates/java/current/bin/javac
  npmPackages:
    @react-native-community/cli: Not Found
    react: 17.0.2 => 17.0.2 
    react-native: 0.67.4 => 0.67.4 
  npmGlobalPackages:
    *react-native*: Not Found

Paste the exact react-native-track-player version you are using

2.2.0-rc3

Real device? Or simulator?

Two simulated devices (one running Android 12, the other Android 9) one real device (Pixel 4 Android 12)

What OS are you running?

Ubuntu 20.04

How I can Help What can you do to help resolve this?

I can test suggested changes

Have you investigated the underlying JS or Swift/Android code causing this bug?

No, I can try but I have very little Java experience and none in Kotlin

Can you create a Pull Request with a fix?

Probably not

[jspizziri]

@mpivchev this looks like a relevant rewrite issue.

@austinried , if you're willing to take a crack at a fix I'm happy to try and provide guidance. It's a great way to learn new tech and level up 😜

[austinried]

Sure, I can poke around at stuff as good as the next person. Just want to set your expectations on what the quality of a Kotlin PR from me would be. 😅

Just in case it's related I will add some info about my build process to #1475 which I suspect could be involved there.

[jspizziri]

No judgement, just appreciation!

I'm sure it'll be great and that's what the remote prices is for anyways 😃.

Also if you need any help feel free to reach out on Discord.

[mpivchev]

Did you receive the Buffering state in rc1 and rc2?

[austinried]

@mpivchev looks like no, I just tested the example app in rc1 and rc2 and it's the same thing, no Buffering state.

[jspizziri]

I've done some investigation here and this is what I've found:

1. The Buffering event is in fact being fired in KotlinAudio as expected.
2. The issue seems to be a combination of 3 things:
   1. Events being emitted in rapid succession overriding one another.
   2. Race conditions between the PLAYING/PAUSED and other events due to how/where they're fired.
   3. A potential issue with how the PAUSED event is emitted.

When playing a track and then skipping to the next one a Buffering event is emitted and then immediately followed by a Paused event (fired by the onIsPlayingChanged) immediately afterwards, resulting in only the Paused event being emitted.

My big question is, why are we even emitting a Paused event in this particular scenario, as no pause was actually caused. If we do need to emit a paused event in this scenario then we have effectively a race-condition scenario. Paused should technically be emitted before the Buffering state, but the buffering state is faster, and therefore getting swallowed.

Here's an example of the event sequencing:

16:08:06.117 stateChange.collect:    IDLE
16:08:06.358 updateAudioPlayerState: LOADING
16:08:06.438 stateChange.collect:    LOADING
16:08:07.778 updateAudioPlayerState: READY
16:08:07.823 stateChange.collect:    READY
16:08:17.893 updateAudioPlayerState: PLAYING
16:08:17.929 stateChange.collect:    PLAYING
16:08:22.019 updateAudioPlayerState: BUFFERING <--- NOTE: this gets emitted but gets swallowed in stateChange.collect by the `PAUSED` event immediately following this line 1ms later. Also it's potentially out of order
16:08:22.020 updateAudioPlayerState: PAUSED
16:08:22.059 stateChange.collect:    PAUSED
16:08:22.411 updateAudioPlayerState: READY     <--- also getting swallowed
16:08:22.412 updateAudioPlayerState: PLAYING
16:08:22.446 stateChange.collect:    PLAYING
16:08:24.553 updateAudioPlayerState: PAUSED
16:08:24.584 stateChange.collect:    PAUSED

The question is, what is the correct event stream? This?

stateChange.collect:    IDLE
updateAudioPlayerState: LOADING
stateChange.collect:    LOADING
updateAudioPlayerState: READY
stateChange.collect:    READY
updateAudioPlayerState: PLAYING
stateChange.collect:    PLAYING
updateAudioPlayerState: PAUSED
stateChange.collect:    PAUSED
updateAudioPlayerState: BUFFERING  <--- NOTE: order changed
stateChange.collect:    BUFFERING  <--- NOTE: was getting swallowed before
updateAudioPlayerState: READY
stateChange.collect:    READY      <--- NOTE: was getting swallowed before
updateAudioPlayerState: PLAYING
stateChange.collect:    PLAYING
updateAudioPlayerState: PAUSED
stateChange.collect:    PAUSED

cc @dcvz @mpivchev

[github-actions[bot]]

This issue is stale because it has been open 90 days with no activity. Remove stale label or comment or this will be closed in 7 days.

[jspizziri]

The fix for this is in place and will be released in v3.2

[bradfloodx]

Here's v3.2 https://github.com/doublesymmetry/react-native-track-player/releases/tag/v3.2.0

Assuming this is done. I'll close this now.