Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Wav file playback error #8388

Closed
amitav13 opened this issue Dec 22, 2020 · 4 comments
Closed

Wav file playback error #8388

amitav13 opened this issue Dec 22, 2020 · 4 comments
Assignees
@ojw28
Labels
bad media duplicate

Comments

@amitav13
Copy link

Hi,
I'm unable to play back some wav files that I've recorded through my app. I've been able to record other files that I can play back though.

The files in question:
Can play:
https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+80.wav

Can't play:
https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+1.wav,
https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+76.wav

I've reproduced this issue in the sample app as well.

media.exolist.json:

...
{
    "name": "User uploaded",
    "samples": [
      {
        "name": "Recording 80 - working",
        "uri": "https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+80.wav"
      },
      {
        "name": "Recording 1 - not working",
        "uri": "https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+1.wav"
      },
      {
        "name": "Recording 76 - not working",
        "uri": "https://temp-audio-bucket-1.s3.ap-south-1.amazonaws.com/Recording+76.wav"
      }
    ]
  }
...

For reference, I've got the same files working as expected when streaming them through the VLC Android app. (https://play.google.com/store/apps/details?id=org.videolan.vlc&hl=en_IN&gl=US)

Stacktrace that I see when trying to play Recording 76:

2020-12-22 19:06:29.332 21782-25610/com.google.android.exoplayer2.demo E/ExoPlayerImplInternal: Playback error
      com.google.android.exoplayer2.ExoPlaybackException: Unexpected runtime error
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:564)
        at android.os.Handler.dispatchMessage(Handler.java:102)
        at android.os.Looper.loop(Looper.java:246)
        at android.os.HandlerThread.run(HandlerThread.java:67)
     Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'java.nio.ByteBuffer java.nio.ByteBuffer.order(java.nio.ByteOrder)' on a null object reference
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.bypassRender(MediaCodecRenderer.java:2206)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:852)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:892)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:467)
        at android.os.Handler.dispatchMessage(Handler.java:102) 
        at android.os.Looper.loop(Looper.java:246) 
        at android.os.HandlerThread.run(HandlerThread.java:67) 
2020-12-22 19:06:29.337 21782-21782/com.google.android.exoplayer2.demo D/EventLogger: audioDisabled [eventTime=1.22, mediaPos=0.00, window=0, period=0]
2020-12-22 19:06:29.338 21782-21782/com.google.android.exoplayer2.demo E/EventLogger: playerFailed [eventTime=1.23, mediaPos=0.00, window=0, period=0
      com.google.android.exoplayer2.ExoPlaybackException: Unexpected runtime error
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:564)
        at android.os.Handler.dispatchMessage(Handler.java:102)
        at android.os.Looper.loop(Looper.java:246)
        at android.os.HandlerThread.run(HandlerThread.java:67)
     Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'java.nio.ByteBuffer java.nio.ByteBuffer.order(java.nio.ByteOrder)' on a null object reference
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.bypassRender(MediaCodecRenderer.java:2206)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:852)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:892)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:467)
        at android.os.Handler.dispatchMessage(Handler.java:102) 
        at android.os.Looper.loop(Looper.java:246) 
        at android.os.HandlerThread.run(HandlerThread.java:67) 
    ]

which is similar to #8374 (comment) - though I have my doubts it's the same root cause as determined on that thread.

The difference in the EventLogger logs that I noticed seemed to point to the codec not getting initialized.

Logs for Recording 1 (not working):

2020-12-22 15:27:24.801 30865-30865/com.vlv.aravali.preprod I/ExoPlayerImpl: Init 74d7b66 [ExoPlayerLib/2.11.8] [y2s, SM-G985F, samsung, 30]
2020-12-22 15:27:24.813 30865-30865/com.vlv.aravali.preprod D/EventLogger: state [eventTime=0.00, mediaPos=0.00, window=0, true, BUFFERING]
2020-12-22 15:27:24.833 30865-30865/com.vlv.aravali.preprod D/EventLogger: seekStarted [eventTime=0.03, mediaPos=0.00, window=0]
2020-12-22 15:27:24.834 30865-30865/com.vlv.aravali.preprod D/EventLogger: positionDiscontinuity [eventTime=0.03, mediaPos=0.00, window=0, SEEK]
2020-12-22 15:27:24.839 30865-30865/com.vlv.aravali.preprod D/EventLogger: mediaPeriodCreated [eventTime=0.03, mediaPos=0.00, window=0]
2020-12-22 15:27:24.848 30865-30865/com.vlv.aravali.preprod D/EventLogger: timeline [eventTime=0.04, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=PREPARED
2020-12-22 15:27:24.848 30865-30865/com.vlv.aravali.preprod D/EventLogger:   period [?]
2020-12-22 15:27:24.848 30865-30865/com.vlv.aravali.preprod D/EventLogger:   window [?, false, false]
2020-12-22 15:27:24.848 30865-30865/com.vlv.aravali.preprod D/EventLogger: ]
2020-12-22 15:27:24.853 30865-30865/com.vlv.aravali.preprod D/EventLogger: loading [eventTime=0.05, mediaPos=0.00, window=0, period=0, true]
2020-12-22 15:27:24.854 30865-30865/com.vlv.aravali.preprod D/EventLogger: seekProcessed [eventTime=0.05, mediaPos=0.00, window=0, period=0]
2020-12-22 15:27:24.973 30865-30865/com.vlv.aravali.preprod D/EventLogger: timeline [eventTime=0.17, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=DYNAMIC
2020-12-22 15:27:24.973 30865-30865/com.vlv.aravali.preprod D/EventLogger:   period [0.00]
2020-12-22 15:27:24.973 30865-30865/com.vlv.aravali.preprod D/EventLogger:   window [0.00, true, false]
2020-12-22 15:27:24.974 30865-30865/com.vlv.aravali.preprod D/EventLogger: ]
2020-12-22 15:27:25.034 30865-30865/com.vlv.aravali.preprod D/EventLogger: decoderEnabled [eventTime=0.23, mediaPos=0.00, window=0, period=0, audio]
2020-12-22 15:27:25.035 30865-30865/com.vlv.aravali.preprod D/EventLogger: tracks [eventTime=0.23, mediaPos=0.00, window=0, period=0, []]
2020-12-22 15:27:25.035 30865-30865/com.vlv.aravali.preprod D/EventLogger: loading [eventTime=0.23, mediaPos=0.00, window=0, period=0, false]
2020-12-22 15:27:25.035 30865-30865/com.vlv.aravali.preprod D/EventLogger: mediaPeriodReadingStarted [eventTime=0.23, mediaPos=0.00, window=0, period=0]
2020-12-22 15:27:25.035 30865-30865/com.vlv.aravali.preprod D/EventLogger: downstreamFormat [eventTime=0.23, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/raw, bitrate=705600, channels=1, sample_rate=44100]
2020-12-22 15:27:25.045 30865-30865/com.vlv.aravali.preprod D/EventLogger: state [eventTime=0.24, mediaPos=0.00, window=0, period=0, true, ENDED]
2020-12-22 15:27:25.050 30865-30865/com.vlv.aravali.preprod D/EventLogger: mediaPeriodReleased [eventTime=0.24, mediaPos=0.00, window=0, period=0]
2020-12-22 15:27:25.051 30865-30865/com.vlv.aravali.preprod D/EventLogger: timeline [eventTime=0.24, mediaPos=0.00, window=0, periodCount=0, windowCount=0, reason=RESET
2020-12-22 15:27:25.051 30865-30865/com.vlv.aravali.preprod D/EventLogger: ]
2020-12-22 15:27:25.053 30865-30865/com.vlv.aravali.preprod D/EventLogger: tracks [eventTime=0.25, mediaPos=0.00, window=0, []]
2020-12-22 15:27:25.053 30865-30865/com.vlv.aravali.preprod D/EventLogger: state [eventTime=0.25, mediaPos=0.00, window=0, true, IDLE]
2020-12-22 15:27:25.061 30865-30865/com.vlv.aravali.preprod D/EventLogger: decoderDisabled [eventTime=0.25, mediaPos=0.00, window=0, audio]

Logs for Recording 80 (working):

2020-12-22 15:32:41.049 30865-30865/com.vlv.aravali.preprod I/ExoPlayerImpl: Release 74d7b66 [ExoPlayerLib/2.11.8] [y2s, SM-G985F, samsung, 30] [goog.exo.core, goog.exo.hls, goog.exo.mediasession]
2020-12-22 15:32:41.053 30865-30865/com.vlv.aravali.preprod I/ExoPlayerImpl: Init 85cce61 [ExoPlayerLib/2.11.8] [y2s, SM-G985F, samsung, 30]
2020-12-22 15:32:41.059 30865-30865/com.vlv.aravali.preprod D/EventLogger: state [eventTime=0.00, mediaPos=0.00, window=0, true, BUFFERING]
2020-12-22 15:32:41.074 30865-30865/com.vlv.aravali.preprod D/EventLogger: seekStarted [eventTime=0.02, mediaPos=0.00, window=0]
2020-12-22 15:32:41.075 30865-30865/com.vlv.aravali.preprod D/EventLogger: positionDiscontinuity [eventTime=0.02, mediaPos=0.00, window=0, SEEK]
2020-12-22 15:32:41.081 30865-30865/com.vlv.aravali.preprod D/EventLogger: mediaPeriodCreated [eventTime=0.03, mediaPos=0.00, window=0]
2020-12-22 15:32:41.094 30865-30865/com.vlv.aravali.preprod D/EventLogger: timeline [eventTime=0.04, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=PREPARED
2020-12-22 15:32:41.094 30865-30865/com.vlv.aravali.preprod D/EventLogger:   period [?]
2020-12-22 15:32:41.094 30865-30865/com.vlv.aravali.preprod D/EventLogger:   window [?, false, false]
2020-12-22 15:32:41.094 30865-30865/com.vlv.aravali.preprod D/EventLogger: ]
2020-12-22 15:32:41.101 30865-30865/com.vlv.aravali.preprod D/EventLogger: loading [eventTime=0.05, mediaPos=0.00, window=0, period=0, true]
2020-12-22 15:32:41.101 30865-30865/com.vlv.aravali.preprod D/EventLogger: seekProcessed [eventTime=0.05, mediaPos=0.00, window=0, period=0]
2020-12-22 15:32:41.228 30865-30865/com.vlv.aravali.preprod D/EventLogger: timeline [eventTime=0.17, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=DYNAMIC
2020-12-22 15:32:41.228 30865-30865/com.vlv.aravali.preprod D/EventLogger:   period [8.40]
2020-12-22 15:32:41.228 30865-30865/com.vlv.aravali.preprod D/EventLogger:   window [8.40, true, false]
2020-12-22 15:32:41.228 30865-30865/com.vlv.aravali.preprod D/EventLogger: ]
2020-12-22 15:32:41.237 30865-30865/com.vlv.aravali.preprod D/EventLogger: decoderEnabled [eventTime=0.18, mediaPos=0.00, window=0, period=0, audio]
2020-12-22 15:32:41.238 30865-30865/com.vlv.aravali.preprod D/EventLogger: tracks [eventTime=0.18, mediaPos=0.00, window=0, period=0, []]
2020-12-22 15:32:41.246 30865-30865/com.vlv.aravali.preprod D/EventLogger: mediaPeriodReadingStarted [eventTime=0.19, mediaPos=0.00, window=0, period=0]
2020-12-22 15:32:41.246 30865-30865/com.vlv.aravali.preprod D/EventLogger: downstreamFormat [eventTime=0.19, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/raw, bitrate=768000, channels=1, sample_rate=48000]
2020-12-22 15:32:41.289 30865-30865/com.vlv.aravali.preprod D/EventLogger: decoderInitialized [eventTime=0.23, mediaPos=0.00, window=0, period=0, audio, c2.android.raw.decoder] <--- Don't see this or steps below in the prior log!
2020-12-22 15:32:41.289 30865-30865/com.vlv.aravali.preprod D/EventLogger: decoderInputFormat [eventTime=0.23, mediaPos=0.00, window=0, period=0, audio, id=null, mimeType=audio/raw, bitrate=768000, channels=1, sample_rate=48000]
2020-12-22 15:32:41.299 30865-30865/com.vlv.aravali.preprod D/EventLogger: state [eventTime=0.24, mediaPos=0.00, window=0, period=0, true, READY]
2020-12-22 15:32:41.301 30865-30865/com.vlv.aravali.preprod D/EventLogger: isPlaying [eventTime=0.25, mediaPos=0.00, window=0, period=0, true]
2020-12-22 15:32:41.330 30865-30865/com.vlv.aravali.preprod D/EventLogger: audioSessionId [eventTime=0.27, mediaPos=0.00, window=0, period=0, 12369]
2020-12-22 15:32:41.330 30865-30865/com.vlv.aravali.preprod D/EventLogger: loading [eventTime=0.27, mediaPos=0.00, window=0, period=0, false]
2020-12-22 15:32:45.776 30865-30865/com.vlv.aravali.preprod D/EventLogger: state [eventTime=4.72, mediaPos=4.23, window=0, period=0, false, READY]
2020-12-22 15:32:45.776 30865-30865/com.vlv.aravali.preprod D/EventLogger: isPlaying [eventTime=4.72, mediaPos=4.23, window=0, period=0, false]

The codec c2.android.raw.decoder should support all these files in theory though.
Screenshot 2020-12-22 at 3 49 10 PM

  • ExoPlayer version number: 2.11.8
  • Android version: 11
  • Android device: Samsung galaxy s20+

Please let me know if any further detail is needed!
@ojw28 ojw28 self-assigned this Dec 23, 2020
@ojw28
Copy link
Contributor

ojw28 commented Dec 23, 2020 •
edited
Loading

Thanks for the high quality bug report! I think there are a couple of things going on here:

  1. It looks like the two files that don't play correctly are malformed. Referring to this page that describes the WAV specification, the Subchunk2Size field in the problematic files is set to 0, which indicates there are zero samples to be played.
  2. The NullPointerException stack trace that you see in the logs occurs when playing an empty WAV files (or zero duration silence), and has the same root cause as the related bug that you found.

Once we fix (2) the stack trace will disappear, but the files will be treated as though they are zero duration with no content to be played, as per the specification. How have you implemented recording? Is it possible there's a bug in your recording code that's causing the issue with the generated files? If so then I think that's something you should resolve on your side.

Note: If I override the Subchunk2Size to assume there's valid WAV data to the end of the file, then the two files do play successfully. This seems dangerous though. There's no particular guarantee that this is the case, so implementing it this way may end up with the player trying to play non-media data, which doesn't seem like a good tradeoff for getting these two specific files playing. We haven't seen any other examples of files with this issue, so it seems likely to be an isolated problem with the way you're recording in your app.

@ojw28
Copy link
Contributor

ojw28 commented Dec 23, 2020

Closing as "bad media" for now. The NullPointerException is already tracked by #8374.

@ojw28 ojw28 closed this as completed Dec 23, 2020
@amitav13
Copy link
Author

Thanks, it was indeed the Subchunk2Size that was the issue.

Would you mind sharing what tools you used to debug this issue btw? We had tried to use all of the Android APIs available, and ffmpeg too to get to this root cause.

@ojw28
Copy link
Contributor

ojw28 commented Dec 30, 2020

I didn't use any tools. I just used the ExoPlayer demo app to play the files, and added some break points and log lines directly into the ExoPlayer source code to figure out what was happening.

@google google locked and limited conversation to collaborators Feb 22, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@ojw28 ojw28

Labels
bad media duplicate
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@amitav13 @ojw28