Subsonic icon indicating copy to clipboard operation
Subsonic copied to clipboard

Incomplete downloads marked as complete

Open magneticflux- opened this issue 1 year ago • 3 comments

When skipping forward past the halfway point in a certain audio file, playback stops and advances to the next song.

~~An example (legal) song exhibiting this behavior: 1-02 Mustin - Now Is the Winter (The Mines of Narshe).zip~~ See below for new info

A snippet from Logcat when the error occurred:

2022-08-01 22:47:41.023 16024-27520/? D/AudioTrack: setVolume: RelativeVolumeFeature, mRelativePercentage:1.000000, left:0.402717, right:0.402717
2022-08-01 22:47:41.024 16024-27521/? I/MediaCodec: (0xead00010) flush
2022-08-01 22:47:41.026 16024-27523/? D/CCodecBuffers: [c2.android.raw.decoder#432:1D-Output.Impl[N]] Client returned a buffer it does not own according to our record: 0
2022-08-01 22:47:41.026 16024-27523/? D/CCodecBuffers: [c2.android.raw.decoder#432:1D-Output.Impl[N]] Client returned a buffer it does not own according to our record: 1
2022-08-01 22:47:41.026 16024-27523/? D/CCodecBuffers: [c2.android.raw.decoder#432:1D-Output.Impl[N]] Client returned a buffer it does not own according to our record: 2
2022-08-01 22:47:41.026 16024-27523/? D/CCodecBuffers: [c2.android.raw.decoder#432:1D-Output.Impl[N]] Client returned a buffer it does not own according to our record: 3
2022-08-01 22:47:41.027 1288-1288/? E/FLACExtractor: FLACParser::readBuffer seek to sample 7658053 failed
2022-08-01 22:47:41.028 16024-27521/? I/MediaCodec: (0xead00010) start
2022-08-01 22:47:41.031 16024-27523/? I/CCodecConfig: query failed after returning 8 values (BAD_INDEX)
2022-08-01 22:47:41.031 16024-27523/? W/Codec2Client: query -- param skipped: index = 1342179345.
2022-08-01 22:47:41.031 16024-27523/? W/Codec2Client: query -- param skipped: index = 2415921170.
2022-08-01 22:47:41.035 16024-27523/? D/CCodecBuffers: [c2.android.raw.decoder#432:Output[N]] popFromStashAndRegister: output format changed to AMessage(what = 0x00000000) = {
      int32_t channel-count = 2
      string mime = "audio/raw"
      int32_t pcm-encoding = 2
      int32_t sample-rate = 44100
    }
2022-08-01 22:47:41.035 16024-27523/? D/CCodecBufferChannel: [c2.android.raw.decoder#432] buffers after EOS ignored (0 us)
2022-08-01 22:47:41.036 16024-27523/? I/chatty: uid=1013(media) NPDecoder-CL identical 1 line
2022-08-01 22:47:41.036 16024-27523/? D/CCodecBufferChannel: [c2.android.raw.decoder#432] buffers after EOS ignored (0 us)
2022-08-01 22:47:41.037 16024-27499/? D/AudioSink: Recycling track for gapless playback
2022-08-01 22:47:41.037 16024-27537/? I/GenericSource: start
2022-08-01 22:47:41.039 16024-27537/? W/Utils: track of type 'audio/raw' does not publish channel mask, channel count 2
2022-08-01 22:47:41.041 25238-25300/? V/Avrcp_ext: onPlaybackStateChanged: state PlaybackState {state=3, position=173652, buffered position=0, speed=1.0, updated=1992836210, actions=4406, custom actions=[Action:mName='Thumbs Down, mIcon=2131230888, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Star, mIcon=2131231119, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Thumbs Up, mIcon=2131230892, mExtras=Bundle[mParcelledData.dataSize=144]], active item id=107899922, error=null}
2022-08-01 22:47:41.041 16024-27537/? W/Utils: track of type 'audio/raw' does not publish channel mask, channel count 2
2022-08-01 22:47:41.042 26462-27482/? E/MediaPlayerNative: internal/external state mismatch corrected
2022-08-01 22:47:41.042 26462-26698/? W/MediaPlayerNative: info/warning (2, 0)
2022-08-01 22:47:41.043 25238-25300/? V/Avrcp_ext: updateCurrentMediaState: mMediaController: MediaController (github.daneren2005.dsub@76a2ad7) Now Is the Winter (The Mines of Narshe), Mustin, Final Fantasy VI: Balance and Ruin
2022-08-01 22:47:41.045 983-1115/? E/qdmetadata: paramType 2048 not supported
2022-08-01 22:47:41.045 983-1115/? E/qdmetadata: paramType 2048 not supported
2022-08-01 22:47:41.045 16022-16053/? I/hash_map_utils: key: 'is_hw_dec_session_available' value: 'audio/raw'
2022-08-01 22:47:41.047 26462-26462/? V/MediaRouter: Selecting route: RouteInfo{ name=Phone, description=null, status=null, category=RouteCategory{ name=System types=ROUTE_TYPE_LIVE_AUDIO ROUTE_TYPE_LIVE_VIDEO  groupable=false }, supportedTypes=ROUTE_TYPE_LIVE_AUDIO ROUTE_TYPE_LIVE_VIDEO , presentationDisplay=null }
2022-08-01 22:47:41.047 25238-25300/? V/Avrcp_ext: isMusicActive: true getBluetoothPlayState: 1
2022-08-01 22:47:41.048 26462-26462/? V/MediaRouter: Selecting route: RouteInfo{ name=Phone, description=null, status=null, category=RouteCategory{ name=System types=ROUTE_TYPE_LIVE_AUDIO ROUTE_TYPE_LIVE_VIDEO  groupable=false }, supportedTypes=ROUTE_TYPE_LIVE_AUDIO ROUTE_TYPE_LIVE_VIDEO , presentationDisplay=null }
2022-08-01 22:47:41.048 25238-25300/? V/Avrcp_ext: updateCurrentMediaState: get media attributes: 
2022-08-01 22:47:41.049 25238-25300/? D/Avrcp_ext:  albumName :Final Fantasy VI: Balance and Ruin device :null
2022-08-01 22:47:41.050 983-1115/? E/qdmetadata: paramType 2048 not supported
2022-08-01 22:47:41.050 16524-16524/? V/MediaTimeout: processState: PlaybackState {state=3, position=173652, buffered position=0, speed=1.0, updated=1992836210, actions=4406, custom actions=[Action:mName='Thumbs Down, mIcon=2131230888, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Star, mIcon=2131231119, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Thumbs Up, mIcon=2131230892, mExtras=Bundle[mParcelledData.dataSize=144]], active item id=107899922, error=null}
2022-08-01 22:47:41.051 16024-27562/? I/MediaCodec: (0xead05870) init name(c2.android.raw.decoder)
2022-08-01 22:47:41.053 25238-25300/? V/Avrcp_ext: Media update: id -1➡107899922? [MediaAttributes: N⋯) - F⋯n by M⋯n (258000 102/0) Game] : [MediaAttributes: N⋯) - F⋯n by M⋯n (258000 102/0) Game]
2022-08-01 22:47:41.053 25238-25300/? D/Avrcp_ext: isPackageNameValid: browsedPackage = github.daneren2005.dsubisValid = true
2022-08-01 22:47:41.053 25238-25300/? V/Avrcp_ext: isBrowseSupported for github.daneren2005.dsub: false
2022-08-01 22:47:41.053 25238-25300/? V/Avrcp_ext: newPlayStatus:1mReportedPlayStatus:-1
2022-08-01 22:47:41.054 25238-25300/? V/Avrcp_ext: updatePlaybackState, state: PlaybackState {state=3, position=173664, buffered position=0, speed=1.0, updated=1992836222, actions=4406, custom actions=[Action:mName='Thumbs Down, mIcon=2131230888, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Star, mIcon=2131231119, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Thumbs Up, mIcon=2131230892, mExtras=Bundle[mParcelledData.dataSize=144]], active item id=107899922, error=null} device: null
2022-08-01 22:47:41.054 25238-25300/? V/Avrcp_ext: Device: no name: 
2022-08-01 22:47:41.054 25238-25300/? I/chatty: uid=1002(bluetooth) BluetoothAvrcpH identical 3 lines
2022-08-01 22:47:41.054 25238-25300/? V/Avrcp_ext: Device: no name: 
2022-08-01 22:47:41.054 25238-25300/? V/Avrcp_ext: updatePlayerStateAndPosition, old=PlaybackState {state=3, position=87483, buffered position=0, speed=1.0, updated=1992833920, actions=4406, custom actions=[Action:mName='Thumbs Down, mIcon=2131230888, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Star, mIcon=2131231119, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Thumbs Up, mIcon=2131230892, mExtras=Bundle[mParcelledData.dataSize=144]], active item id=107899922, error=null}, state=PlaybackState {state=3, position=173664, buffered position=0, speed=1.0, updated=1992836222, actions=4406, custom actions=[Action:mName='Thumbs Down, mIcon=2131230888, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Star, mIcon=2131231119, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Thumbs Up, mIcon=2131230892, mExtras=Bundle[mParcelledData.dataSize=144]], active item id=107899922, error=null}
2022-08-01 22:47:41.054 25238-25300/? V/Avrcp_ext: old state = PlaybackState {state=3, position=87483, buffered position=0, speed=1.0, updated=1992833920, actions=4406, custom actions=[Action:mName='Thumbs Down, mIcon=2131230888, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Star, mIcon=2131231119, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Thumbs Up, mIcon=2131230892, mExtras=Bundle[mParcelledData.dataSize=144]], active item id=107899922, error=null}, new state= PlaybackState {state=3, position=173664, buffered position=0, speed=1.0, updated=1992836222, actions=4406, custom actions=[Action:mName='Thumbs Down, mIcon=2131230888, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Star, mIcon=2131231119, mExtras=Bundle[mParcelledData.dataSize=144], Action:mName='Thumbs Up, mIcon=2131230892, mExtras=Bundle[mParcelledData.dataSize=144]], active item id=107899922, error=null}

The source of the error in AOSP: https://android.googlesource.com/platform/frameworks/av/+/master/media/extractors/flac/FLACExtractor.cpp#587

I believe this is a DSub issue because the Nextcloud media player, VLC media player, YouTube Music, and the Android Files app all play the file fine.

magneticflux- avatar Aug 02 '22 04:08 magneticflux-

I pulled a downloaded file from my Android device and it seems to be truncated at offset 0x1378000. An example: Downloaded by DSub: 215-The Impresario (Opera Sequence).complete.zip Original file: https://nextcloud.skaggsm.com/s/ytbJnxn6nzKoEFQ

magneticflux- avatar Oct 08 '22 23:10 magneticflux-

I just encountered it again with a different track and file type. 09-The Spine (Transistor).complete.wav was truncated at offset 0x27e2000 where the original was length 0x3214510. It might have something to do with changing networks mid-download incorrectly marking the downloads as complete?

magneticflux- avatar Oct 11 '22 13:10 magneticflux-

I saw this happening, and I was using mobile connection which could easily drop and change during the trip.

DarthGandalf avatar Apr 18 '23 07:04 DarthGandalf