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.

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

Output format M4A/AAC corrupt (missing moov header?) #143

Closed
JeroenHid opened this issue Oct 5, 2022 · 33 comments
Closed

Output format M4A/AAC corrupt (missing moov header?) #143

JeroenHid opened this issue Oct 5, 2022 · 33 comments
Assignees
Labels
bug/limitation elsewhere Bug/limitation in the ROM or another project

Comments

@JeroenHid
Copy link

Hi,

First of all, I love the simplicity of this app. Keep it that way!

I do noticed that the recorder does record conversations, but the generated m4a/aac files cannot be played correctly.
I tried to fix them with e.g. ffmpeg, but it seems the moov header is missing? Not sure tough, as I'm not familiar with the aac format.

See attached files for a few examples.
calls.zip

Here's one with debuglogging:
with debuglog.zip

I'm using BCR version 1.20 (release + debugmode)
Installed /enabled as Magisk module
On Android 9, running on Samsuing S8 stock firmware (rooted obviously).

Output dir is default (com.chiller3.bcr/file), format is also default (m4a/aac, 64kbps, 48kHz)
App Permissions are Contacts and Microphone

Although I'm not in favor submitting multiple issues at the same time, I also notice that the debug file is often missing, or sometimes has a size of 0 bytes.

Hope you can help,
Thanks!

@JeroenHid
Copy link
Author

chenxiaolong added a commit that referenced this issue Oct 5, 2022
The buffer size of `logcat -d` may not be enough to preserve all of the
logs.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 5, 2022
First attempt at trying to understand why the `moov` atom is not being
written on older Android devices.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 5, 2022
First attempt at trying to understand why the `moov` atom is not being
written on older Android devices.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
@chenxiaolong
Copy link
Owner

chenxiaolong commented Oct 5, 2022

Glad you're enjoying the app!

This is an interesting bug. It looks like in every recording, Android's MediaMuxer is not finalizing the files at all. Several headers are missing (including moov) and the file size header is set to 1061109567 bytes (which is ???? in ASCII text).

It's a bit difficult to tell what's going on because Android 9's muxer doesn't have many debug logs and it silently ignores errors in several places. If certain errors occur, Android seems to intentionally skip writing the moov header.

Can you give this debug build a try and upload the new debug logs? BCR-1.21.r6.g4bc5cdb-debug.zip There are two changes:

Also, how much free space is available in the default output directory?

EDIT: This might be a lot harder to troubleshoot than I thought. I took a quick look at the Galaxy S8's /system/lib64/libstagefright.so (where the MediaMuxer code is) and it is very different from the open source AOSP code for Android 9.

@JeroenHid
Copy link
Author

JeroenHid commented Oct 5, 2022 via email

@JeroenHid
Copy link
Author

JeroenHid commented Oct 5, 2022 via email

@chenxiaolong
Copy link
Owner

Thanks for the new recording and log file! Unfortunately, not much new information.

Can you give this app a try and upload its output file? MuxMpeg4Test.zip (It's just a regular .apk, not a Magisk module. The app does not require any permissions.)

The test app is BCR, but with all features stripped out. The only thing it does is encode silence into an m4a/aac file. That way, we can test just the encoder without anything else possibly affecting the process.

If this output file is also broken, then there's a good chance this is a bug in the Samsung stock Android 9 firmware and you might have to pick a different output format for call recording.

chenxiaolong added a commit that referenced this issue Oct 5, 2022
The buffer size of `logcat -d` may not be enough to preserve all of the
logs.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
@JeroenHid
Copy link
Author

Thnx for the test APK!
Managed to run it this morning :
encode_test.zip

Looks like this one is playing well.
Can you confirm by having a look at the header?

Thnx!

@chenxiaolong
Copy link
Owner

Hmm, that file does indeed look normal! It has moov and all of the other headers. Screenshot

I wonder why BCR doesn't work then. The encoding settings are identical (64Kbps, 48kHz). The only difference is that the audio comes from the call recording "microphone" instead of just being silent.

One more test: can you try a longer recording with the test app? (eg. around 45+ seconds to match the initial BCR recordings)

@JeroenHid
Copy link
Author

encode_test_45sec.zip

It's playable in VLC....

@JeroenHid
Copy link
Author

I see it's not 45+ sec....but 44.

I'll post another

@JeroenHid
Copy link
Author

This one is longer
encode_test_60.zip

@chenxiaolong
Copy link
Owner

Thanks for the new uploads! Those both look good.

Can you give this debug build of BCR a try? BCR-1.21.r5.gac4c3be-debug.zip Please make 2 recordings: once using the default output directory and once using a custom one.

@JeroenHid
Copy link
Author

Ok, done.

  1. installed the module, and rebooted the phone
  2. made a call (default location)
  3. changed the location to a custom one (on SD card)
  4. made a 2nd call.

I did notice a few strange things concerning the logs:

  • after the first call ( to default location) the debug logfile wasn't completely flushed to disk, it seemed.
  • it was before/during the second call (custom location configured) that the logfile of the 1st call was completely on disk (default location).
  • and: the after 2nd call, the call recording was at the custom location, but the logfile was still at the default location.

My guess: logfiles are always stored at the default location ?

Anyway, these are the recordings.
Sorry to say, but I can't play either... :-(

default location.zip
custom location.zip

@chenxiaolong
Copy link
Owner

after the first call ( to default location) the debug logfile wasn't completely flushed to disk, it seemed.

Hmm, that's extremely weird. BCR stops logging and closes the file 1 second after the call ends. You might be on to something though. If the files are somehow not being flushed properly, maybe that's what's happening to the audio file too. Android does not write the headers until the very end when closing the file.

My guess: logfiles are always stored at the default location ?

BCR always writes the log to the default location first and then moves the file to the custom location when the call is complete. (or at least it's supposed to...)


I'll make one more debug build after work today to try a new idea: I'll made BCR record to the internal app directory in /data/data/com.chiller3.bcr/files. That should bypass Android's SAF (storage access framework) just in case that's causing issues.

@chenxiaolong
Copy link
Owner

chenxiaolong commented Oct 6, 2022

Please give this build a try: BCR-1.21.r9.g559d30a-debug.zip

It'll write the audio and log files to /data/data/com.chiller3.bcr/files (the output directory setting is completely ignored), so you'll need to use root to access the output files.

EDIT: Forgot to mention, this build has two changes: it writes to the internal app directory and also forces a flush via fsync

@JeroenHid
Copy link
Author

Hi,

I tried r9, see files:

calls-r9.zip

Files were indeed stored at /data/data/com.chiller3.bcr/files, both logfiles and call recording.

The logfile was still flushed, until a second call was made. Really stange.
I think the recording is still not ok unfortunately.

@JeroenHid
Copy link
Author

JeroenHid commented Oct 7, 2022

I do see this error in the log:
MPEG4Writer: The mp4 file will not be streamable.
Is this normal?
It looks like this is an error:
https://stackoverflow.com/questions/23934087/non-streamable-video-file-created-with-mediamuxer

Strange thing is that the encode_test APK does seem to produce a valid recording file. It doesn't produce a logfile, so it's hard to compare.

@chenxiaolong
Copy link
Owner

chenxiaolong commented Oct 7, 2022

Thanks for the new upload! One thing I noticed the logs when you make 2 calls is this:

10-07 01:41:51.865 13535 15085 I RecorderThread/880: Recording thread started
10-07 01:41:51.865 13535 15085 D RecorderThread/880: Creating 20221007_014149.012+0200_<phone number> with MIME type audio/mp4 in file:///data/user/0/com.chiller3.bcr/files
...
10-07 01:48:02.913 13535 13535 D RecorderInCallService: onDetailsChanged: Call [id: TC@2, state: CONNECTING, <...>
...
10-07 01:48:03.826 13535 15085 D RecorderThread/880: Input complete after 45.5s

It looks like the call is only around 45 seconds, but BCR doesn't stop trying to record the first call until 6 minutes later (at 01:48) when you make the second call. I think either Android is not notifying BCR that the call is complete or if it is notifying, maybe BCR doesn't understand the message. This would explain why the files appear as if they're incomplete and not flushed.

EDIT: Please use this new debug build of BCR for the test below: BCR-1.21.r10.g6898f68-debug.zip

If you have adb, can you:

  • Run adb logcat > logcat.txt
  • Try to record a call
  • Cancel adb logcat with Control+C
  • Upload logcat.txt. Please feel free to edit the file because the Android OS logs might contain your phone number. If you prefer not to upload publicly, you can also email me at accounts+github<at>chiller3.com.

I am hoping these logs will show how Android is telling BCR that the call is complete.


I do see this error in the log:
MPEG4Writer: The mp4 file will not be streamable.
Is this normal?

Yep, that is perfectly normal. That message is printed right after the moov header is written. The file is not streamable because Android puts the moov header at the end of the file. If you tried to play the audio file via a web browser, it would have to download the whole file until it reaches moov before it will play (thus, "not streamable").

@JeroenHid
Copy link
Author

Hi, thanks for your patience!

I'll try to make a logcat in the morning (3am here now)...
Will post or email it!

@chenxiaolong
Copy link
Owner

No problem! We'll find a way to solve it 🙂

@JeroenHid
Copy link
Author

e-mail has been sent, 2 calls + logs, and logcat

chenxiaolong added a commit that referenced this issue Oct 7, 2022
The output files should generally be unique, but that's not guaranteed.
Without truncation, the output files may potentially be corrupted due to
the presence of old data at the end.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 7, 2022
The output files should generally be unique, but that's not guaranteed.
Without truncation, the output files may potentially be corrupted due to
the presence of old data at the end.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 7, 2022
Call.Callback.onStateChanged() is not guaranteed to be called for
STATE_DISCONNECTING or STATE_DISCONNECTED. This is documented behavior
that was overlooked. While it worked on firmware with fewer changes on
top of AOSP, it does not work on Samsung devices.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
@chenxiaolong
Copy link
Owner

Thanks for the email!

Yep, this is a Samsung firmware bug. The Android/Samsung telephony framework is failing to notify apps when calls end. It's not just BCR, it's also failing to notify Samsung's own Knox-related components.

Specifically, it's not notifying about any of these 3 events:

  • onStateChanged for Call.STATE_DISCONNECTED
  • onCallDestroyed
  • onCallRemoved

However, it does happen to send a onDetailsChanged event with Call.STATE_DISCONNECTED (which doesn't happen on my Google Pixel 6 Pro). I think I can find a way to abuse this to make BCR stop recording.

@chenxiaolong chenxiaolong self-assigned this Oct 7, 2022
@chenxiaolong chenxiaolong added the bug/limitation elsewhere Bug/limitation in the ROM or another project label Oct 7, 2022
@JeroenHid
Copy link
Author

Thanks, that would be great!

Then, other Samsung models are likely to experience the same issue ?

chenxiaolong added a commit that referenced this issue Oct 7, 2022
On older Samsung firmware, the telephony framework fails to notify
InCallService implementations about call disconnections. This doesn't
just happen with BCR. It affects Samsung's own apps too, like Knox's
InCallServiceImpl.

Due to this bug, none of the following callbacks are called when a call
ends:

* Call.Callback.onStateChanged with Call.STATE_DISCONNECTING or
  Call.STATE_DISCONNECTED
* Call.Callback.onCallDestroyed
* InCallService.onCallRemoved

However, it does happen to call Call.Callback.onDetailsChanged when the
call state transitions to Call.STATE_DISCONNECTED (which doesn't happen
with AOSP).

This commit reworks RecorderInCallService to keep track of calls better
in the face of these firmware bugs. A call's lifetime begins when
InCallService.onCallAdded is called and ends when either
InCallService.onCallDestroyed is called or the state is
Call.STATE_DISCONNECTING or Call.STATE_DISCONNECTED in any other
callback.

This should work on both well-behaved firmware, like AOSP, and buggy
firmware, like Samsung's OneUI.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
@chenxiaolong
Copy link
Owner

Please give this debug build a try and grab the full logcat: BCR-1.21.r14.gf7ede65-debug.zip Really hope this one does the trick!

This build adds a workaround to try and detect the end of calls via onDetailsChanged. Also, the temporary output directory changes were removed. It records to the specified output directory like normal now.

Then, other Samsung models are likely to experience the same issue ?

Yep, I think that's likely, at least for other devices running Samsung's Android 9 firmware. I'm not sure if it's fixed in newer Samsung firmware--I would need to see a logcat to know.

@JeroenHid
Copy link
Author

Hi, I installed the module twice, but in the app itself the version keeps showing r9, where I expected r14 (as in the file name).
Not sure if this is an explanation, but I notice no difference in behavior after a call has ended.
Calls4.zip

@chenxiaolong
Copy link
Owner

Hmm, that's weird. Can you uninstall the module, run adb uninstall com.chiller3.bcr, and then reinstall r14?

I'm not sure why it wouldn't upgrade.

@JeroenHid
Copy link
Author

I've tried adb uninstall, it gave an exception/stack trace...

C:\Temp\adb>adb uninstall com.chiller3.bcr

Exception occurred while executing:
java.lang.IllegalArgumentException: Unknown package: com.chiller3.bcr

Then, I downloaded the package again, installed as module in Magisk, see logfile.
Rebooted.
However, the version seems the same.

I've tried installing app-debug.apk, but the version stayed 1.21-r9.

Hmmm, may we talk about different things?

  • version in Magisk module is r14
  • version in App Manager of Android is r14
  • version in the bottom of the app main screen is r9

Am I missing something?

@JeroenHid
Copy link
Author

As a test, I installed release 1.20, and the version displayed in the app's page was so 1
20.
My guess would be the package 1.21-r14 contains some old code?
Can that be

@chenxiaolong
Copy link
Owner

chenxiaolong commented Oct 8, 2022

  • version in Magisk module is r14
  • version in App Manager of Android is r14
  • version in the bottom of the app main screen is r9

Ah, I see. I misunderstood what you were saying before. I decompiled the apk and it does look like old code ended in there somehow. I've never seen that happen before.

I've rebuilt r14 from scratch. This should no longer include any old code. BCR-1.21.r14.gf7ede65-debug.zip

EDIT: Even though the version field said r9, looks like the new code was present. I'm looking through the latest logs you uploaded now.

chenxiaolong added a commit that referenced this issue Oct 8, 2022
On older Samsung firmware, the telephony framework fails to notify
InCallService implementations about call disconnections. This doesn't
just happen with BCR. It affects Samsung's own apps too, like Knox's
InCallServiceImpl.

Due to this bug, none of the following callbacks are called when a call
ends:

* Call.Callback.onStateChanged with Call.STATE_DISCONNECTING or
  Call.STATE_DISCONNECTED
* Call.Callback.onCallDestroyed
* InCallService.onCallRemoved

However, it does happen to call Call.Callback.onDetailsChanged when the
call state transitions to Call.STATE_DISCONNECTED (which doesn't happen
with AOSP).

This commit reworks RecorderInCallService to keep track of calls better
in the face of these firmware bugs. A call's lifetime begins when
InCallService.onCallAdded is called and ends when either
InCallService.onCallDestroyed is called or the state is
Call.STATE_DISCONNECTING or Call.STATE_DISCONNECTED in any other
callback.

This should work on both well-behaved firmware, like AOSP, and buggy
firmware, like Samsung's OneUI.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 8, 2022
On Samsung devices, when a call ends, AudioRecord.read() blocks until
another call becomes active, which prevents recordings from stopping at
the correct time. This behavior does not happen in AOSP.

To work around this, use non-blocking reads with a sleep interval of the
AudioRecord minimum buffer size. This gives the recording loop a chance
to check if recording has been cancelled.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
@chenxiaolong
Copy link
Owner

Please give this build a try: BCR-1.21.r16.gdd3cbe7-debug.zip

Based on the previous logs, BCR is now able to detect the end of the call, but is not able to cancel the recording. I added a workaround for that in this new build.

@JeroenHid
Copy link
Author

Calls5.zip
Looks good!!!
I can play the recorded aac file.

I'll keep this version and try it the next few days

Thanks for all the hard work!

@chenxiaolong
Copy link
Owner

Awesome, thanks for being so patient and helping with testing!

chenxiaolong added a commit that referenced this issue Oct 9, 2022
On older Samsung firmware, the telephony framework fails to notify
InCallService implementations about call disconnections. This doesn't
just happen with BCR. It affects Samsung's own apps too, like Knox's
InCallServiceImpl.

Due to this bug, none of the following callbacks are called when a call
ends:

* Call.Callback.onStateChanged with Call.STATE_DISCONNECTING or
  Call.STATE_DISCONNECTED
* Call.Callback.onCallDestroyed
* InCallService.onCallRemoved

However, it does happen to call Call.Callback.onDetailsChanged when the
call state transitions to Call.STATE_DISCONNECTED (which doesn't happen
with AOSP).

This commit reworks RecorderInCallService to keep track of calls better
in the face of these firmware bugs. A call's lifetime begins when
InCallService.onCallAdded is called and ends when either
InCallService.onCallDestroyed is called or the state is
Call.STATE_DISCONNECTING or Call.STATE_DISCONNECTED in any other
callback.

This should work on both well-behaved firmware, like AOSP, and buggy
firmware, like Samsung's OneUI.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 9, 2022
On older Samsung firmware, the telephony framework fails to notify
InCallService implementations about call disconnections. This doesn't
just happen with BCR. It affects Samsung's own apps too, like Knox's
InCallServiceImpl.

Due to this bug, none of the following callbacks are called when a call
ends:

* Call.Callback.onStateChanged with Call.STATE_DISCONNECTING or
  Call.STATE_DISCONNECTED
* Call.Callback.onCallDestroyed
* InCallService.onCallRemoved

However, it does happen to call Call.Callback.onDetailsChanged when the
call state transitions to Call.STATE_DISCONNECTED (which doesn't happen
with AOSP).

This commit reworks RecorderInCallService to keep track of calls better
in the face of these firmware bugs. A call's lifetime begins when
InCallService.onCallAdded is called and ends when either
InCallService.onCallRemoved is called or the state is
Call.STATE_DISCONNECTING or Call.STATE_DISCONNECTED in any other
callback.

This should work on both well-behaved firmware, like AOSP, and buggy
firmware, like Samsung's OneUI.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 9, 2022
On Samsung devices, when a call ends, AudioRecord.read() blocks until
another call becomes active, which prevents recordings from stopping at
the correct time. This behavior does not happen in AOSP.

To work around this, use non-blocking reads with a sleep interval of the
AudioRecord minimum buffer size. This gives the recording loop a chance
to check if recording has been cancelled.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
chenxiaolong added a commit that referenced this issue Oct 9, 2022
On Samsung devices, when a call ends, AudioRecord.read() blocks until
another call becomes active, which prevents recordings from stopping at
the correct time. This behavior does not happen in AOSP.

To work around this, use non-blocking reads with a sleep interval of the
AudioRecord minimum buffer size. This gives the recording loop a chance
to check if recording has been cancelled.

Issue: #143

Signed-off-by: Andrew Gunnerson <chillermillerlong@hotmail.com>
@chenxiaolong
Copy link
Owner

Version 1.22 has been released! The code is identical to the debug build you're already running.

If you run into any further issues, feel free to create a new issue.

@JeroenHid
Copy link
Author

Calls5.zip Looks good!!! I can play the recorded aac file.

I'll keep this version and try it the next few days

Thanks for all the hard work!

Used the current release (1.22) for a while and works as expected !!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug/limitation elsewhere Bug/limitation in the ROM or another project
Projects
None yet
Development

No branches or pull requests

2 participants