Playback of current track suddenly restarts to beginning, seemingly random

austinried commented 3 years ago

Describe the bug Every couple of tracks the player seems to randomly decide to restart the track from the beginning. There are no events to indicate this has happened (buffering, track changed, etc) and it seems to happen a random amount of time into the track.

To Reproduce Set up a queue with a few songs in it, play the queue from the beginning and wait for one of the tracks to restart.

Environment (please complete the following information):

System:
    OS: Linux 5.4 Ubuntu 20.04.2 LTS (Focal Fossa)
    CPU: (8) x64 Intel(R) Core(TM) i7-8650U CPU @ 1.90GHz
    Memory: 1.01 GB / 15.39 GB
    Shell: 5.0.17 - /bin/bash
  Binaries:
    Node: 14.17.0 - /tmp/yarn--1627869882542-0.5886444297880513/node
    Yarn: 1.22.10 - /tmp/yarn--1627869882542-0.5886444297880513/yarn
    npm: 7.16.0 - ~/.nvm/versions/node/v14.17.0/bin/npm
    Watchman: 4.9.0 - /usr/bin/watchman
  SDKs:
    Android SDK: Not Found
  IDEs:
    Android Studio: Not Found
  Languages:
    Java: 1.8.0_292 - /usr/bin/javac
  npmPackages:
    @react-native-community/cli: Not Found
    react: 17.0.1 => 17.0.1 
    react-native: 0.64.1 => 0.64.1 
  npmGlobalPackages:
    *react-native*: Not Found

react-native-track-player version: rc-18 and 1.2.7 Testing on a real device (Pixel 4, Android 11) and emulator (Pixel 3a, Android 10)

I don't really know what code to share, this is a decent sized app and there's a lot of it that touches the track player, so please let me know what parts would be of interest. I'm not calling setupPlayer() with any options (although I have tried playing with the buffer settings and it didn't seem to make a difference).

Here's the log of events, not that there is much here, when an instance of this happened:

 LOG  playback-state: {"state":3,"type":"playback-state"}
 LOG  playback-track-changed: {"position":203.261,"nextTrack":1,"track":0,"type":"playback-track-changed"}
 LOG  playback-track-changed: {"position":211.415,"nextTrack":2,"track":1,"type":"playback-track-changed"}

The track restarted about a minute into track 2, and no event was generated when it did (I'm listening to all of them for debugging).

austinried commented 3 years ago

Got a little more information that I don't know if it's relevant or not, but I repro'd this again in the emulator while I had Flipper running to watch the logs and got these:

Time    PID Tag Message
16:45:53.667    19948   RNTrackPlayer   onPositionDiscontinuity: 4
16:45:53.686    1648    AudioFlinger    createTrack_l(): mismatch between requested flags (00000008) and output flags (00000006)
16:45:53.689    1648    AudioFlinger    Client defaulted notificationFrames to 6000 for frameCount 12000
16:45:53.690    1648    AF::TrackHandle OpPlayAudio: track:1380 usage:1 not muted

This was right at the time the track restarted.

dcvz commented 3 years ago

Interesting bug @austinried -- does this happen to you if you create a larger queue on the example app? Could you try to put some of your app's queue in the example and see if it happens there?

It'd be great to have a project where that happens so I can look into it.

austinried commented 3 years ago

Sorry for the delay here, this has taken a bit of time to narrow down due to how long it seems to take to repro. At the moment I think this is actually on my end now, related to the source I'm using (Navidrome/Subsonic servers, seemingly only when transcoding is enabled). I'm going to close this for now due to it probably being an issue outside with RNTP.

doublesymmetry / react-native-track-player

Playback of current track suddenly restarts to beginning, seemingly random #1219