younglo / cyanogenmod4milestone

Automatically exported from code.google.com/p/cyanogenmod4milestone
0 stars 0 forks source link

MediaRecorder randomly fails to work #546

Open GoogleCodeExporter opened 8 years ago

GoogleCodeExporter commented 8 years ago
I'm an android developer and I developed a application to use MediaRecorder to 
record voice. It used to work well when my milestone is still with android 2.1 
version.

Recently I flashed the Rom CM 7.1 RC3 for my milestone. But I frequently failed 
to record voice by my application.

I checked the logs, found the followings(just part of them):
05-18 19:14:21.663: WARN/IMediaDeathNotifier(18711): media server died
05-18 19:14:21.663: INFO/ServiceManager(1399): service 'media.audio_flinger' 
died
05-18 19:14:21.663: INFO/ServiceManager(1399): service 'media.player' died
05-18 19:14:21.663: INFO/ServiceManager(1399): service 'media.camera' died
05-18 19:14:21.663: INFO/ServiceManager(1399): service 'media.audio_policy' died
05-18 19:14:21.678: WARN/IMediaDeathNotifier(18325): media server died
05-18 19:14:21.678: WARN/AudioSystem(18325): AudioFlinger server died!
05-18 19:14:21.686: WARN/AudioSystem(18325): AudioPolicyService server died!
05-18 19:14:21.702: WARN/AudioSystem(1715): AudioFlinger server died!
05-18 19:14:21.702: WARN/AudioSystem(1715): AudioPolicyService server died!

I have no idea why these "servers" died. I did nothing special, just click a 
button to start record.

However, it will work successfully sometimes, just for luck.
So I suppose it's due to the problem about bottom implement of hardware or 
driver level of the CM7 rom. Could anyone please help me explain this strange 
issue?

Thanks,
Timmy

Original issue reported on code.google.com by imtimmyz on 18 May 2011 at 11:14

GoogleCodeExporter commented 8 years ago
I need to see the log of what happened before the mediaserver died. What you 
posted is happening to late and the actual cause of the death is not there.

Original comment by kabal...@gmail.com on 18 May 2011 at 11:27

GoogleCodeExporter commented 8 years ago
05-18 21:50:03.912: DEBUG/AudioHardwareMot(20137): 
AudioHardwareMot::openInputStream enter
05-18 21:50:03.912: DEBUG/AudioHardwareMot(20137): 
AudioStreamInMot::set(0xaf48, 40000, 1, 10, 8000)
05-18 21:50:03.912: DEBUG/AudioHardwareMot(20137): Codec sampling rate already 
8000
05-18 21:50:03.912: ERROR/AudioPostProcessor(20137): Error:Beamformer request 
ignored: missing parameters
05-18 21:50:03.912: DEBUG/AudioPostProcessor(20137): Done updating beamformer 
library
05-18 21:50:03.912: DEBUG/AudioHardwareMot(20137): Input bufSize from kernel = 
800
05-18 21:50:03.912: DEBUG/AudioHardwareMot(20137): Input 0x14990 entering 
standby
05-18 21:50:03.928: DEBUG/TIOMX_CORE(20137): Found component OMX.TI.AMR.encode 
with refCount 0
05-18 21:50:03.951: DEBUG/OMX_NBAMRENC(20137): OMX_ComponentInit():216 Entering 
OMX_ComponentInit
05-18 21:50:03.951: INFO/MPEG4Writer(20137): limits: 2147483647/0 bytes/us, bit 
rate: 12200 bps and the estimated moov size 3072 bytes
05-18 21:50:03.951: DEBUG/AudioFlinger(20137): setParameters(): io 20, keyvalue 
input_source=1;routing=262144, tid 20149, calling tid 20137
05-18 21:50:03.951: DEBUG/AudioHardwareMot(20137): 
AudioStreamInMot::setParameters() input_source=1;routing=262144
05-18 21:50:03.951: DEBUG/AudioHardwareMot(20137): set input routing 40000
05-18 21:50:03.951: DEBUG/AudioHardwareMot(20137): doRouting called
05-18 21:50:03.951: DEBUG/AudioHardwareMot(20137): Routing to earpiece
05-18 21:50:03.951: DEBUG/AudioHardwareMot(20137): Input path: 
DEVICE_IN_BUILTIN_MIC
05-18 21:50:03.951: DEBUG/AudioHardwareMot(20137): doRouting: setup input path
05-18 21:50:03.951: DEBUG/AudioHardwareMot(20137): Gain for Input accy = 0 is 28
05-18 21:50:03.959: DEBUG/AudioHardwareMot(20137): Codec sampling rate already 
8000
05-18 21:50:03.959: DEBUG/AudioHardwareMot(20137): Input 0x14990 exiting standby
05-18 21:50:03.959: DEBUG/AudioHardwareMot(20137): doRouting called
05-18 21:50:03.959: DEBUG/AudioHardwareMot(20137): Routing to earpiece
05-18 21:50:03.959: DEBUG/AudioHardwareMot(20137): Input path: 
DEVICE_IN_BUILTIN_MIC
05-18 21:50:04.053: INFO/OMX_NBAMRENC(20137): addstatetranstion: 1 @ 1
05-18 21:50:04.053: INFO/OMXCodec(20137): [OMX.TI.AMR.encode] allocating 5 
buffers of size 2048 on input port
05-18 21:50:04.053: INFO/OMXCodec(20137): [OMX.TI.AMR.encode] allocating 9 
buffers of size 8192 on output port
05-18 21:50:04.092: WARN/IMediaDeathNotifier(23269): media server died
05-18 21:50:04.092: INFO/ServiceManager(1399): service 'media.audio_flinger' 
died
05-18 21:50:04.092: INFO/ServiceManager(1399): service 'media.player' died
05-18 21:50:04.092: INFO/ServiceManager(1399): service 'media.camera' died
05-18 21:50:04.092: INFO/ServiceManager(1399): service 'media.audio_policy' died
05-18 21:50:04.099: WARN/AudioSystem(1799): AudioFlinger server died!
05-18 21:50:04.099: WARN/AudioSystem(1799): AudioPolicyService server died!
05-18 21:50:04.099: WARN/AudioSystem(1715): AudioFlinger server died!
05-18 21:50:04.099: WARN/AudioSystem(1715): AudioPolicyService server died!
05-18 21:50:04.099: WARN/IMediaDeathNotifier(23305): media server died
05-18 21:50:04.107: WARN/AudioSystem(23305): AudioFlinger server died!
05-18 21:50:04.107: WARN/AudioSystem(23305): AudioPolicyService server died!
05-18 21:50:04.131: ERROR/Error: 100(23269): 0
05-18 21:50:04.670: INFO/(23329): ServiceManager: 0xadc8
05-18 21:50:04.678: DEBUG/AudioHardwareMot(23329): mixer fd = 8
05-18 21:50:04.678: DEBUG/AudioMgrIPC(23329): Inside am_aipcm_init
05-18 21:50:04.678: DEBUG/AudioMgrIPC(23329): am_aipcm_init: mux_txrx_fd = 9
05-18 21:50:04.678: DEBUG/AudioMgrIPC(23329): Read thread spawned
05-18 21:50:04.678: DEBUG/AudioPostProcessor(23329): AudioPostProcessor()
05-18 21:50:04.685: DEBUG/AudioPostProcessor(23329): Could not load beamformer 
parameters. Feature Disabled.
05-18 21:50:04.685: DEBUG/AudioPostProcessor(23329): No debug parameters in 
/data; checking ro.product.brand
05-18 21:50:04.685: DEBUG/AudioPostProcessor(23329): ro.product.brand value = 
MOTO_RTEU
05-18 21:50:04.685: DEBUG/AudioPostProcessor(23329): /system/bin/ap_gain.bin 
file size is 50371
05-18 21:50:04.685: DEBUG/AudioMgrIPC(23329): am_aipcm_read_thread called
05-18 21:50:04.685: DEBUG/AudioMgrIPC(23329): Setting Select ipc_fd
05-18 21:50:04.693: DEBUG/AudioPostProcessor(23329): Read format version 0xc08, 
content version 0xc0c from /system/bin/ap_gain.bin
05-18 21:50:04.693: DEBUG/AudioPostProcessor(23329): Successfully parsed 
parameters from /system/bin/ap_gain.bin
05-18 21:50:04.693: DEBUG/AudioMsgHandler(23329): The new thread spawned 
successfully
05-18 21:50:04.693: DEBUG/AudioHardwareMot(23329): This is not a Begonia; 
ignoring ro.audio_disable_primary_mic
05-18 21:50:04.693: DEBUG/AudioHardwareMot(23329): setMode(NORMAL)
05-18 21:50:04.693: INFO/CameraService(23329): CameraService started (pid=23329)
05-18 21:50:04.693: DEBUG/AudioHardwareMot(23329): 
AudioHardwareMot::openOutputStream enter
05-18 21:50:04.693: DEBUG/AudioHardwareMot(23329): 
AudioStreamOutMot::set(0xaf48, 2, 0, 0 0)
05-18 21:50:04.701: DEBUG/AudioMsgHandler(23329): server_fd = 18
05-18 21:50:04.709: DEBUG/AudioHardwareMot(23329): Output bufSize from kernel = 
8192
05-18 21:50:04.717: INFO/AudioFlinger(23329): AudioFlinger's thread 0xcc58 
ready to run
05-18 21:50:04.717: DEBUG/AudioHardwareMot(23329): Output bufSize from kernel = 
8192
05-18 21:50:04.724: DEBUG/AudioHardwareMot(23329): Output bufSize from kernel = 
8192
05-18 21:50:04.724: DEBUG/AudioHardwareMot(23329): AudioStreamOutMot::standby 
called
05-18 21:50:04.732: DEBUG/AudioHardwareMot(23329): Output bufSize from kernel = 
8192
05-18 21:50:04.740: DEBUG/AudioFlinger(23329): setParameters(): io 1, keyvalue 
routing=2, tid 23334, calling tid 23329
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): 
AudioStreamOutMot::setParameters() routing=2
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): set output routing 2
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): doRouting called
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): Routing to speaker
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): doRouting: setup input path
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): doRouting: setup output path
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): configPostProcessor() called 
with accy = 0
05-18 21:50:04.740: DEBUG/AudioPostProcessor(23329): configPostProcessing() 
called, inputAccy= 32, outputAccy= 0, sampleRate= 44100, ringtoneMode= 0
05-18 21:50:04.740: DEBUG/AudioPostProcessor(23329): updatePostProcessor 
calling SuperAPI parser with: accy=8 config=0 SE_level_index=1
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): Gain for Input accy = 0 is 28
05-18 21:50:04.740: DEBUG/AudioHardwareMot(23329): Gain for Output accy = 0 is 
13
05-18 21:50:04.748: DEBUG/AudioHardwareMot(23329): setVoiceVolume called with 
vol = 1.000000, converted intVol = 7
05-18 21:50:04.748: DEBUG/AudioMgrIPC(23329): am_aipcm_set_volume_req() called 
with vol_level = 7, vol_type = 2
05-18 21:50:04.748: DEBUG/AudioMgrIPC(23329): Message sent for message id 3
05-18 21:50:04.748: DEBUG/AudioMgrIPC(23329): select returned, need to do a read
05-18 21:50:04.748: DEBUG/AudioMgrIPC(23329): ID 0x8000, Tag 0x8100: Ack 
received for message with id = 3
05-18 21:50:05.615: ERROR/AudioService(1715): Media server died.
05-18 21:50:05.631: ERROR/AudioService(1715): Media server started.
05-18 21:50:05.646: DEBUG/AudioHardwareMot(23329): Output bufSize from kernel = 
8192
05-18 21:50:05.646: DEBUG/AudioFlinger(23329): setParameters(): io 0, keyvalue 
restarting=true, tid 23329, calling tid 1715
05-18 21:50:05.646: ERROR/AudioHardwareMot(23329): Error:Unsupported key = 
restarting=true
05-18 21:50:05.646: DEBUG/AudioHardwareMot(23329): setMode(NORMAL)
05-18 21:50:05.646: WARN/AudioPolicyManagerBase(23329): setPhoneState() setting 
same state 0
05-18 21:50:05.670: DEBUG/AudioFlinger(23329): setParameters(): io 0, keyvalue 
restarting=false, tid 23329, calling tid 1715
05-18 21:50:05.670: ERROR/AudioHardwareMot(23329): Error:Unsupported key = 
restarting=false
05-18 21:50:06.646: DEBUG/dalvikvm(21842): GC_EXPLICIT freed 7K, 50% free 
2710K/5379K, external 0K/0K, paused 67ms
05-18 21:50:06.974: INFO/ActivityManager(1715): Process 
com.google.android.apps.maps:LocationFriendService (pid 23255) has died.
05-18 21:50:07.068: INFO/ActivityManager(1715): Process android.process.media 
(pid 23290) has died.
05-18 21:50:14.451: ERROR/dalvikvm(23337): could not disable core file 
generation for pid 23337: Operation not permitted
05-18 21:50:14.459: INFO/ActivityManager(1715): Start proc 
com.google.android.apps.maps:LocationFriendService for service 
com.google.android.apps.maps/com.google.googlenav.friend.android.LocationFriendS
ervice: pid=23337 uid=10020 gids={3003, 1015}
05-18 21:50:14.763: DEBUG/dalvikvm(23337): GC_CONCURRENT freed 139K, 47% free 
3043K/5639K, external 0K/0K, paused 10ms+4ms
05-18 21:50:15.217: DEBUG/dalvikvm(23337): GC_CONCURRENT freed 119K, 44% free 
3388K/6023K, external 0K/0K, paused 3ms+5ms
05-18 21:50:19.185: DEBUG/dalvikvm(4043): GC_EXPLICIT freed <1K, 51% free 
2786K/5575K, external 0K/0K, paused 49ms
05-18 21:50:26.638: DEBUG/dalvikvm(22866): GC_EXPLICIT freed 74K, 52% free 
3365K/6983K, external 211K/694K, paused 62ms

Thanks!

Original comment by imtimmyz on 18 May 2011 at 3:14

GoogleCodeExporter commented 8 years ago
Here is my logic to record voice:

            mRecorder = new MediaRecorder();
            mRecorder.setAudioSource(MediaRecorder.AudioSource.MIC);
                       mRecorder.setOutputFormat(MediaRecorder.OutputFormat.THREE_GPP);
            mRecorder.setAudioEncoder(MediaRecorder.AudioEncoder.AMR_NB);
            mRecorder.setOutputFile(strAudioPath);
            mRecorder.setOnErrorListener(errorListener);
            mRecorder.setOnInfoListener(infoListener);
            try {
                mRecorder.prepare();
                mRecorder.start();
            } catch (IllegalStateException e) {
                Log.e("MediaRecorder",e.toString());
                e.printStackTrace();
            } catch (IOException e) {
                Log.e("MediaRecorder",e.toString());
                e.printStackTrace();
            }

Original comment by imtimmyz on 18 May 2011 at 3:46

GoogleCodeExporter commented 8 years ago
It's very strange that there is nothing in the log about the reason of the 
media server death.
Nevertheless, the exception handling in your code does not seem to me right.
Look how it is done in SoundRecorder:
https://github.com/CyanogenMod/android_packages_apps_SoundRecorder/blob/gingerbr
ead/src/com/android/soundrecorder/Recorder.java#L146
I haven't experienced any failure when testing the recording in the 
SoundRecorder app.

Original comment by kabal...@gmail.com on 18 May 2011 at 4:08

GoogleCodeExporter commented 8 years ago
I replace my exception handling part with these according to SoundRecorder:

            // Handle IOException
            try {
                mRecorder.prepare();
            } catch(IOException exception) {
                Log.i("MediaRecorder", "INTERNAL_ERROR");
                mRecorder.reset();
                mRecorder.release();
                mRecorder = null;
                return;
            }
            // Handle RuntimeException if the recording couldn't start
            try {
                mRecorder.start();
            } catch (RuntimeException exception) {
                AudioManager audioMngr = (AudioManager)context.getSystemService(Context.AUDIO_SERVICE);
                boolean isInCall = audioMngr.getMode() == AudioManager.MODE_IN_CALL;
                Log.i("MediaRecorder", String.valueOf(isInCall));
                mRecorder.reset();
                mRecorder.release();
                mRecorder = null;
                return;
            }

However, the problem still exists.
What's more, I find that the two exceptions seem never to be fired as there 
isn't any log tagged "MediaRecorder" when media servers died.
So I think the problem is not happened when recorder is prepare() or start(). 
The media server just died inexplicably. Really weird.  

Original comment by imtimmyz on 18 May 2011 at 4:33

GoogleCodeExporter commented 8 years ago
Isn't there something relevant even more early in the log?

Original comment by kabal...@gmail.com on 18 May 2011 at 4:38

GoogleCodeExporter commented 8 years ago
The log I posted is from the moment I click the button to start till I click a 
button to stop. I think it's quite simple.

I just find a more interesting thing. The camera doesn't work, either.

Intent it = new Intent(MediaStore.ACTION_IMAGE_CAPTURE);
startActivityForResult(it, 10);

This is a very general way to call camera to take a picture and get the picture 
back.
It used to work well. Now when it calls up camera and I click the camera button 
to take a photo, the "Insert" or "OK" button will never show, just a "Cancel" 
button.

I check the log, find that "media server died" again.

Log is too long, please refer to the attachment. (pay attention to the lines 
from 05-19 00:44:47.561):

Original comment by imtimmyz on 18 May 2011 at 4:53

Attachments:

GoogleCodeExporter commented 8 years ago
Hi, any updates?

Original comment by imtimmyz on 22 May 2011 at 5:27