FP3+ crashes on messenger calls (IAudioFlinger)
- /e/ version: 0.14-q-2021012698290-dev-FP3
- Device model(s): FP3+
Summary
Sometimes the phone crashes on internet messenger calls.
Reproduced with:
- Wire: https://play.google.com/store/apps/details?id=com.wire
- you can call using a second account on https://app.wire.com via a PC for testing
- Threema: https://shop.threema.ch
- you'll need 2 phones and two accounts for testing
- Skype Lite App: https://play.google.com/store/apps/details?id=com.skype.m2
- Sometimes crashes even before accepting the call (phone just vibrates, no ringtone).
- Conversations: https://f-droid.org/de/packages/eu.siacs.conversations/
- Using two jabber.de accounts on two phones. (server must support XEP-0215 for voice calls)
The problem
- Lock the screen on your FP3+. (until now I only reproduced the bug when the screen was locked)
- Call from another device.
- Pick up the call on the FP3+.
- Talk for a few seconds.
- The bug doesn't always appear. But if it appears it usually happens in the first 15 seconds.
What is the current behavior?
About 1 in 4 times the phone crashes. But mostly with Threema when the screen is locked and NO headphones are attached. If you want to test for the bug with Threema, you can either buy Threema here or just ask me (I'll happily gift you a Threema license for helping to solve this).
Sometimes the audio just stops. (you can't hear the caller anymore) Also other sounds won't be working anymore.
Sometimes there is a message telling, that the messenger app (Wire / Threema) doesn't respond anymore. But clicking "close app" doesn't help. Also the navigation bar might still be visible, but won't react. The rest of the screen if either black or unresponsive. If you turn off the screen (power button) it won't turn on again. After some minutes Zygote seems to try a restart (boot logo appears without showing the bootloader logo first). But it stays at that boot logo (looks like a bootloop).
Devices still responds to adb.
Restarting the phone via adb shell reboot
or long pressing the power button reboots the phone. Afterwards the phone works fine again.
Technical informations
These LineageOS issues seem to handle the same bug:
- https://gitlab.com/LineageOS/issues/android/-/issues/2933
- https://gitlab.com/LineageOS/issues/android/-/issues/3016
Listening to music and videos (for example via NewPipe) works fine for hours. Classical phone calls also seem to be fine. Also the recorder app (org.lineageos.recorder) works fine.
Phone is connected via WLAN / WiFi. (SIM active but mobile data disabled)
A friend who's running /e/ Android-9 on his FP3 (NOT FP3+) doesn't seem to have that problem.
I can provide more logs if needed. Just ask.
Critical logcat section tested with Wire, but Threema and Skype-Lite look mostly identical (always IAudioFlinger crashing)
03-04 23:47:50.200 5808 5852 D GmsGcmMcsInput: Incoming message: DataMessageStanza{id=00C666AC, from=782078216207, to=f2cOSn89Xfc, category=com.wire, app_data=[AppData{key=google.c.sender.id, value=782078216207}, AppData{key=data, value=\{"id":"a6a8fa16-7d3b-11eb-8006-22000a53120a"\}}, AppData{key=type, value=notice}, AppData{key=user, value=6e4f3add-b865-4482-a0a6-b2e4fd0842f4}], persistent_id=0:1614898071841744%d8a830d2f9fd7ecd, last_stream_id_received=2, ttl=2419200, sent=1614898071838}
03-04 23:47:50.297 5808 5852 D GmsGcmMcsSvc: Adding app com.wire for userId 0 to the temp whitelist
03-04 23:47:50.310 5808 5852 D GmsGcmMcsSvc: Deliver message to all receivers in package com.wire
03-04 23:47:51.454 9655 9655 I Choreographer: Skipped 67 frames! The application may be doing too much work on its main thread.
03-04 23:47:51.533 5808 5808 D GmsGcmRegister: onBind: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms }
03-04 23:47:51.561 5808 5808 D GmsGcmRegister: handleMessage: package=com.wire what=2 id=1
03-04 23:47:51.561 5808 5808 D GmsGcmRegister: Ack 0:1614898071841744%d8a830d2f9fd7ecd for com.wire
03-04 23:47:51.574 5808 5831 D GmsGcmMcsSvc: Ack initiated, reason: Intent { act=org.microg.gms.gcm.mcs.ACK cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
03-04 23:47:51.575 5808 5853 D GmsGcmMcsOutput: Outgoing message: IqStanza{type=SET, id=, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=4, status=0}
03-04 23:47:51.644 612 9761 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:52.486 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: ctor@[name=Thread-157, id=871]
03-04 23:47:52.488 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: Sample rate is set to 48000 Hz
03-04 23:47:52.513 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseAcousticEchoCanceler: true
03-04 23:47:52.513 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseNoiseSuppressor: true
03-04 23:47:52.516 9655 9766 W org.webrtc.Logging: WebRtcAudioManager: AAudio support is currently disabled on all devices!
03-04 23:47:52.521 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: Android SDK: 29, Release: 10, Brand: Fairphone, Device: FP3, Id: QQ3A.200805.001, Hardware: qcom, Manufacturer: Fairphone, Model: FP3, Product: FP3
03-04 23:47:52.523 695 732 W DeviceHAL: Error from HAL Device in function get_mic_mute: Function not implemented
03-04 23:47:52.524 695 732 W DeviceHAL: Error from HAL Device in function get_mic_mute: Function not implemented
03-04 23:47:52.526 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: Audio State: audio mode: MODE_NORMAL, has mic: true, mic muted: false, music active: false, speakerphone: false, BT SCO: false
03-04 23:47:52.527 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: Audio State:
03-04 23:47:52.527 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: fixed volume=false
03-04 23:47:52.530 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: STREAM_VOICE_CALL: volume=5, max=5, muted=false
03-04 23:47:52.533 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: STREAM_MUSIC: volume=0, max=15, muted=false
03-04 23:47:52.536 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: STREAM_RING: volume=7, max=7, muted=false
03-04 23:47:52.539 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: STREAM_ALARM: volume=7, max=7, muted=false
03-04 23:47:52.542 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: STREAM_NOTIFICATION: volume=7, max=7, muted=false
03-04 23:47:52.545 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: STREAM_SYSTEM: volume=7, max=7, muted=false
03-04 23:47:52.557 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: Audio Devices:
03-04 23:47:52.558 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: TYPE_BUILTIN_EARPIECE(out): channels=[1], encodings=[2], sample rates=[48000], id=2
03-04 23:47:52.559 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: TYPE_BUILTIN_SPEAKER(out): channels=[2], encodings=[2], sample rates=[48000], id=3
03-04 23:47:52.559 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: TYPE_TELEPHONY(out): channels=[1, 2], encodings=[2], sample rates=[8000, 16000], id=10
03-04 23:47:52.560 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: TYPE_BUILTIN_MIC(in): channels=[1, 2, 3, 4, 6], encodings=[2], sample rates=[8000, 11025, 12000, 16000, 22050, 24000, 32000, 44100, 48000], id=16
03-04 23:47:52.560 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: TYPE_BUILTIN_MIC(in): channels=[1, 2, 3, 4, 6], encodings=[2], sample rates=[8000, 11025, 12000, 16000, 22050, 24000, 32000, 44100, 48000], id=17
03-04 23:47:52.561 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: TYPE_FM_TUNER(in): channels=[1, 2], encodings=[2], sample rates=[8000, 11025, 12000, 16000, 22050, 24000, 32000, 44100, 48000], id=13
03-04 23:47:52.561 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: TYPE_TELEPHONY(in): channels=[1, 2], encodings=[2], sample rates=[8000, 11025, 12000, 16000, 22050, 24000, 32000, 44100, 48000], id=14
03-04 23:47:52.566 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: ctor@[name=Thread-157, id=871]
03-04 23:47:52.570 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: ctor@[name=Thread-157, id=871]
03-04 23:47:52.570 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: ctor@[name=Thread-157, id=871]
03-04 23:47:52.570 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: init@[name=Thread-157, id=871]
03-04 23:47:52.572 9655 9766 I org.webrtc.Logging: WebRtcAudioManager: audio mode is: MODE_NORMAL
03-04 23:47:52.575 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: enableBuiltInAEC(true)
03-04 23:47:52.575 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: setAEC(true)
03-04 23:47:52.576 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseAcousticEchoCanceler: true
03-04 23:47:52.576 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: enableBuiltInNS(true)
03-04 23:47:52.576 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: setNS(true)
03-04 23:47:52.576 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseNoiseSuppressor: true
03-04 23:47:52.607 9655 9721 W AudioManager: Use of stream types is deprecated for operations other than volume control
03-04 23:47:52.607 9655 9721 W AudioManager: See the documentation of requestAudioFocus() for what to use instead with android.media.AudioAttributes to qualify your playback use case
03-04 23:47:52.614 9655 9721 W AudioManager: Use of stream types is deprecated for operations other than volume control
03-04 23:47:52.614 9655 9721 W AudioManager: See the documentation of requestAudioFocus() for what to use instead with android.media.AudioAttributes to qualify your playback use case
03-04 23:47:52.619 9655 9721 D avs AudioRouter: GetAudioRoute() Earpiece
03-04 23:47:52.622 9655 9721 D avs AudioRouter: EnableSpeaker
03-04 23:47:52.624 755 3878 D AudioPolicyManagerCustom: setForceUse() usage 0, config 1, mPhoneState 0
03-04 23:47:52.722 1645 1746 E VibratorService: Ignoring incoming vibration as process with uid= 10159 is background, attrs= AudioAttributes: usage=USAGE_UNKNOWN content=CONTENT_TYPE_UNKNOWN flags=0x800 tags= bundle=null
03-04 23:47:52.726 932 932 D NuPlayerDriver: NuPlayerDriver(0xeaa5c820) created, clientPid(9655)
03-04 23:47:52.726 9655 9696 D FlowManager: getVideoCaptureDevices: 2
03-04 23:47:52.730 932 932 I Codec2Client: Creating a Codec2 client to service "software"
03-04 23:47:52.736 932 932 I Codec2Client: Client to Codec2 service "software" created
03-04 23:47:52.741 9655 9721 W MediaPlayer: Use of stream types is deprecated for operations other than volume control
03-04 23:47:52.742 9655 9721 W MediaPlayer: See the documentation of setAudioStreamType() for what to use instead with android.media.AudioAttributes to qualify your playback use case
03-04 23:47:52.743 932 932 D NuPlayerDriver: reset(0xeaa5c820) at state 2
03-04 23:47:52.746 932 9773 D NuPlayerDriver: notifyResetComplete(0xeaa5c820)
03-04 23:47:52.746 932 932 D NuPlayerDriver: reset(0xeaa5c820) at state 0
03-04 23:47:52.748 9655 9721 V MediaPlayer: resetDrmState: mDrmInfo=null mDrmProvisioningThread=null mPrepareDrmInProgress=false mActiveDrmScheme=false
03-04 23:47:52.748 9655 9721 V MediaPlayer: cleanDrmObj: mDrmObj=null mDrmSessionId=null
03-04 23:47:52.748 9655 9721 W MediaPlayer: Use of stream types is deprecated for operations other than volume control
03-04 23:47:52.748 9655 9721 W MediaPlayer: See the documentation of setAudioStreamType() for what to use instead with android.media.AudioAttributes to qualify your playback use case
03-04 23:47:52.751 932 932 D NuPlayerDriver: NuPlayerDriver(0xeaa5c820) created, clientPid(9655)
03-04 23:47:52.754 932 932 I Codec2Client: Creating a Codec2 client to service "software"
03-04 23:47:52.759 932 932 I Codec2Client: Client to Codec2 service "software" created
03-04 23:47:52.765 932 9776 D GenericSource: FileSource remote
03-04 23:47:52.802 9374 9374 D WM-DelayedWorkTracker: Scheduling work 8ace4118-4b99-41ee-934d-5d6361d14aa7
03-04 23:47:52.808 932 9775 I GenericSource: start
03-04 23:47:52.824 932 9780 D CCodec : allocate(c2.android.aac.decoder)
03-04 23:47:52.825 972 2427 V C2Store : in init
03-04 23:47:52.825 972 2427 V C2Store : loading dll
03-04 23:47:52.834 932 9780 I CCodec : Created component [c2.android.aac.decoder]
03-04 23:47:52.835 932 9780 D CCodecConfig: read media type: audio/mp4a-latm
03-04 23:47:52.841 932 9780 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.max-count.values
03-04 23:47:52.842 932 9780 D ReflectedParamUpdater: extent() != 1 for single value type: output.subscribed-indices.values
03-04 23:47:52.842 932 9780 D ReflectedParamUpdater: extent() != 1 for single value type: input.buffers.allocator-ids.values
03-04 23:47:52.842 932 9780 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.allocator-ids.values
03-04 23:47:52.843 932 9780 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.allocator-ids.values
03-04 23:47:52.843 932 9780 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
03-04 23:47:52.843 932 9780 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.pool-ids.values
03-04 23:47:52.855 932 9780 I CCodecConfig: query failed after returning 16 values (BAD_INDEX)
03-04 23:47:52.856 932 9780 D CCodecConfig: c2 config diff is Dict {
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 coded.aac-packaging.value = 0
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 coded.bitrate.value = 64000
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 coded.pl.level = 0
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 coded.pl.profile = 8192
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::float coding.drc.attenuation-factor.value = 1
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::float coding.drc.boost-factor.value = 1
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::i32 coding.drc.compression-mode.value = 3
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::i32 coding.drc.effect-type.value = 3
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::float coding.drc.encoded-level.value = 0.25
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::float coding.drc.reference-level.value = -16
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 input.buffers.max-size.value = 8192
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 input.delay.value = 0
03-04 23:47:52.856 932 9780 D CCodecConfig: string input.media-type.value = "audio/mp4a-latm"
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 output.delay.value = 2
03-04 23:47:52.856 932 9780 D CCodecConfig: string output.media-type.value = "audio/raw"
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 raw.channel-count.value = 1
03-04 23:47:52.856 932 9780 D CCodecConfig: c2::u32 raw.sample-rate.value = 44100
03-04 23:47:52.856 932 9780 D CCodecConfig: }
03-04 23:47:52.862 932 9780 D CCodecConfig: no c2 equivalents for durationUs
03-04 23:47:52.862 932 9780 D CCodecConfig: no c2 equivalents for language
03-04 23:47:52.862 932 9780 D CCodecConfig: no c2 equivalents for encoder-delay
03-04 23:47:52.862 932 9780 D CCodecConfig: no c2 equivalents for encoder-padding
03-04 23:47:52.862 932 9780 D CCodecConfig: no c2 equivalents for aac-profile
03-04 23:47:52.863 932 9780 D CCodecConfig: config failed => CORRUPTED
03-04 23:47:52.864 932 9780 D CCodecConfig: c2 config diff is c2::u32 raw.channel-count.value = 2
03-04 23:47:52.865 932 9780 W Codec2Client: query -- param skipped: index = 1107298332.
03-04 23:47:52.865 932 9780 D CCodec : client requested max input size 1412, which is smaller than what component recommended (8192); overriding with component recommendation.
03-04 23:47:52.865 932 9780 W CCodec : This behavior is subject to change. It is recommended that app developers double check whether the requested max input size is in reasonable range.
03-04 23:47:52.865 932 9780 D CCodec : setup formats input: AMessage(what = 0x00000000) = {
03-04 23:47:52.865 932 9780 D CCodec : int32_t channel-count = 2
03-04 23:47:52.865 932 9780 D CCodec : int32_t level = 0
03-04 23:47:52.865 932 9780 D CCodec : int32_t max-input-size = 8192
03-04 23:47:52.865 932 9780 D CCodec : string mime = "audio/mp4a-latm"
03-04 23:47:52.865 932 9780 D CCodec : int32_t profile = 2
03-04 23:47:52.865 932 9780 D CCodec : int32_t sample-rate = 44100
03-04 23:47:52.865 932 9780 D CCodec : } and output: AMessage(what = 0x00000000) = {
03-04 23:47:52.865 932 9780 D CCodec : int32_t channel-count = 2
03-04 23:47:52.865 932 9780 D CCodec : string mime = "audio/raw"
03-04 23:47:52.865 932 9780 D CCodec : int32_t sample-rate = 44100
03-04 23:47:52.865 932 9780 D CCodec : int32_t encoder-delay = 2112
03-04 23:47:52.865 932 9780 D CCodec : int32_t encoder-padding = 789
03-04 23:47:52.865 932 9780 D CCodec : }
03-04 23:47:52.865 932 9780 I MediaCodec: MediaCodec will operate in async mode
03-04 23:47:52.869 932 9780 W Codec2Client: query -- param skipped: index = 1342179345.
03-04 23:47:52.869 932 9780 W Codec2Client: query -- param skipped: index = 2415921170.
03-04 23:47:52.869 932 9780 W Codec2Client: query -- param skipped: index = 1610614798.
03-04 23:47:52.872 932 9780 D CCodecBufferChannel: [c2.android.aac.decoder#725] Created input block pool with allocatorID 16 => poolID 20 - OK (0)
03-04 23:47:52.872 972 972 D BufferPoolAccessor: bufferpool2 0x334c79b230 : 0(0 size) total buffers - 0(0 size) used buffers - 90/96 (recycle/alloc) - 6/96 (fetch/transfer)
03-04 23:47:52.872 972 972 D BufferPoolAccessor: Destruction - bufferpool2 0x334c79b230 cached: 0/0M, 0/0% in use; allocs: 96, 94% recycled; transfers: 96, 94% unfetced
03-04 23:47:52.872 972 1130 D BufferPoolAccessor: bufferpool2 0x334c798830 : 0(0 size) total buffers - 0(0 size) used buffers - 17/21 (recycle/alloc) - 4/21 (fetch/transfer)
03-04 23:47:52.872 972 1130 D BufferPoolAccessor: Destruction - bufferpool2 0x334c798830 cached: 0/0M, 0/0% in use; allocs: 21, 81% recycled; transfers: 21, 81% unfetced
03-04 23:47:52.873 972 972 D BufferPoolAccessor: bufferpool2 0x334c799c30 : 0(0 size) total buffers - 0(0 size) used buffers - 17/22 (recycle/alloc) - 5/22 (fetch/transfer)
03-04 23:47:52.873 972 972 D BufferPoolAccessor: Destruction - bufferpool2 0x334c799c30 cached: 0/0M, 0/0% in use; allocs: 22, 77% recycled; transfers: 22, 77% unfetced
03-04 23:47:52.877 3526 3526 D NotificationRepository: updateNotification() called with: list = [1]
03-04 23:47:52.889 932 2004 D BufferPoolAccessor: bufferpool2 0xe5936010 : 0(0 size) total buffers - 0(0 size) used buffers - 15/26 (recycle/alloc) - 11/24 (fetch/transfer)
03-04 23:47:52.890 932 2004 D BufferPoolAccessor: Destruction - bufferpool2 0xe5936010 cached: 0/0M, 0/0% in use; allocs: 26, 58% recycled; transfers: 24, 54% unfetced
03-04 23:47:52.890 932 2004 D BufferPoolAccessor: bufferpool2 0xe5935410 : 0(0 size) total buffers - 0(0 size) used buffers - 14/26 (recycle/alloc) - 12/23 (fetch/transfer)
03-04 23:47:52.890 932 2004 D BufferPoolAccessor: Destruction - bufferpool2 0xe5935410 cached: 0/0M, 0/0% in use; allocs: 26, 54% recycled; transfers: 23, 48% unfetced
03-04 23:47:52.890 932 9780 I CCodecBufferChannel: [c2.android.aac.decoder#725] Created output block pool with allocatorID 16 => poolID 32 - OK
03-04 23:47:52.892 932 9780 D CCodecBufferChannel: [c2.android.aac.decoder#725] Configured output block pool ids 32 => OK
03-04 23:47:52.899 972 9781 D SimpleC2Component: Using output block pool with poolID 32 => got 32 - 0
03-04 23:47:52.908 972 9781 I C2SoftAacDec: Reconfiguring decoder: 0->44100 Hz, 0->2 channels
03-04 23:47:52.912 1645 1746 I ActivityTaskManager: START u0 {cmp=com.wire/com.waz.zclient.calling.CallingActivity} from uid 10159
03-04 23:47:52.915 1645 1746 W ActivityTaskManager: startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.wire/com.waz.zclient.calling.CallingActivity }
03-04 23:47:52.946 695 732 D audio_hw_primary: adev_get_parameters:vr_audio_mode_on
03-04 23:47:52.946 695 732 I audio_hw_primary: getting vr mode to 0
03-04 23:47:52.946 695 732 D audio_hw_primary: adev_get_parameters: exit: returns - vr_audio_mode_on=false
03-04 23:47:52.946 755 1935 I hash_map_utils: key: 'vr_audio_mode_on' value: ''
03-04 23:47:52.947 755 1935 I AudioPolicyManagerCustom: VR mode is 0, switch to primary output if request is for fast|raw
03-04 23:47:52.947 755 1935 I AudioPolicyManagerCustom: FLAG None hence request for a primary output
03-04 23:47:52.949 755 1935 W AudioFlinger: createTrack_l(): mismatch between requested flags (00000008) and output flags (00000006)
03-04 23:47:52.949 755 1935 D AudioFlinger: Client defaulted notificationFrames to 11025 for frameCount 22050
03-04 23:47:52.953 755 1935 D AF::TrackHandle: OpPlayAudio: track:62 usage:6 not muted
03-04 23:47:52.984 695 732 D audio_hw_primary: out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=2
03-04 23:47:52.984 695 732 D audio_hw_extn: audio_extn_set_anc_parameters: anc_enabled:0
03-04 23:47:52.984 695 732 D audio_hw_spkr_prot: audio_extn_fbsp_set_parameters: Speaker protection disabled
03-04 23:47:52.996 695 8642 D audio_hw_primary: start_output_stream: enter: stream(0xed40a800)usecase(1: low-latency-playback) devices(0x2)
03-04 23:47:52.997 695 8642 D audio_hw_primary: select_devices for use case (low-latency-playback)
03-04 23:47:52.997 695 8642 D audio_hw_primary: select_devices: out_snd_device(2: speaker) in_snd_device(0: )
03-04 23:47:52.997 695 8642 I msm8916_platform: platform_check_and_set_codec_backend_cfg:becf: afe: bitwidth 16, samplerate 48000 channels 2, backend_idx 0 usecase = 1 device (speaker)
03-04 23:47:52.997 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(1) new_snd_devices(0)
03-04 23:47:52.997 695 8642 I msm8916_platform: platform_check_and_set_codec_backend_cfg: becf: new_snd_devices[0] is speaker
03-04 23:47:52.997 695 8642 I msm8916_platform: platform_check_codec_backend_cfg:becf: afe: Codec selected backend: 0 current bit width: 16 sample rate: 48000 channels: 2 usecase 1 device (speaker)
03-04 23:47:52.997 695 8642 D msm8916_platform: platform_check_codec_backend_cfg:becf: afe: playback on codec device not supporting native playback set default Sample Rate(48k)
03-04 23:47:52.997 695 8642 I msm8916_platform: platform_check_codec_backend_cfg:becf: afe: Codec selected backend: 0 updated bit width: 16 sample rate: 48000 channels: 2
03-04 23:47:52.997 695 8642 D audio_hw_primary: check_usecases_codec_backend:becf: force routing 0
03-04 23:47:52.997 695 8642 E msm8916_platform: platform_check_backends_match: Invalid snd_device =
03-04 23:47:52.997 695 8642 D audio_hw_primary: check_usecases_codec_backend:becf: (65) check_usecases curr device: speaker, usecase device: backends match 0
03-04 23:47:52.997 695 8642 D audio_hw_primary: check_usecases_codec_backend:becf: check_usecases num.of Usecases to switch 0
03-04 23:47:52.997 695 8642 D hardware_info: hw_info_append_hw_type : device_name = speaker
03-04 23:47:52.997 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(0) new_snd_devices(0)
03-04 23:47:52.997 695 8642 D audio_hw_primary: enable_snd_device: snd_device(2: speaker)
03-04 23:47:52.997 695 8642 I soundtrigger: audio_extn_sound_trigger_update_device_status: device 0x2 of type 0 for Event 1, with Raise=0
03-04 23:47:52.997 695 8642 D audio_route: Apply path: speaker
03-04 23:47:52.997 695 8642 D soundtrigger: audio_extn_sound_trigger_update_stream_status: uc_info->id 1 of type 0 for Event 3, with Raise=0
03-04 23:47:52.997 695 8642 D audio_hw_utils: audio_extn_utils_send_app_type_cfg: usecase->out_snd_device speaker
03-04 23:47:52.997 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(0) new_snd_devices(0)
03-04 23:47:52.998 695 8642 D audio_hw_utils: audio_extn_btsco_get_sample_rate:Not a BT SCO device, need not update sampling rate
03-04 23:47:52.998 695 8642 I audio_hw_utils: send_app_type_cfg_for_device PLAYBACK app_type 69937, acdb_dev_id 14, sample_rate 48000, snd_device_be_idx 2
03-04 23:47:52.999 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(1) new_snd_devices(0)
03-04 23:47:52.999 695 8642 D audio_hw_utils: audio_extn_btsco_get_sample_rate:Not a BT SCO device, need not update sampling rate
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> send_audio_cal, acdb_id = 14, path = 0, app id = 0x11131, sample rate = 48000, afe_sample_rate = 48000
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> send_asm_topology
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TOPOLOGY_ID
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> send_adm_topology
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TOPOLOGY_ID
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> send_audtable
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE_SIZE
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> AUDIO_SET_AUDPROC_CAL cal_type[11] acdb_id[14] app_type[69937]
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> send_audvoltable
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE_SIZE
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE, vol index 0
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> AUDIO_SET_VOL_CAL cal type = 12
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TABLE_SIZE
03-04 23:47:52.999 695 8642 D ACDB-LOADER: ACDB -> send_audstrmtable
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TABLE_V2
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> audstrm_cal->cal_type.cal_data.cal_size = 16
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> send_afe_topology
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_TOPOLOGY_ID
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> GET_AFE_TOPOLOGY_ID for adcd_id 14, Topology Id 1025e
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> send_afe_cal
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> AUDIO_SET_AFE_CAL cal_type[16] acdb_id[14]
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> send_hw_delay : acdb_id = 14 path = 0
03-04 23:47:53.000 695 8642 D ACDB-LOADER: ACDB -> ACDB_AVSYNC_INFO: ACDB_CMD_GET_DEVICE_PROPERTY
03-04 23:47:53.000 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(0) new_snd_devices(0)
03-04 23:47:53.000 695 8642 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 2
03-04 23:47:53.000 695 8642 D audio_hw_primary: enable_audio_route: apply mixer and update path: low-latency-playback
03-04 23:47:53.000 695 8642 D audio_route: Apply path: low-latency-playback
03-04 23:47:53.006 695 8642 D audio_hw_primary: select_devices: done
03-04 23:47:53.012 695 8642 D msm8916_platform: platform_set_channel_map mixer_ctl_name:Playback Channel Map12
03-04 23:47:53.013 695 8642 D msm8916_platform: platform_set_channel_map: set mapping(1 2 0 0 0 0 0 0) for channel:2
03-04 23:47:53.069 695 8642 D audio_hw_primary: start_output_stream: exit
03-04 23:47:53.069 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(0) new_snd_devices(0)
03-04 23:47:53.069 695 8642 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 2
03-04 23:47:53.162 1645 3381 I PowerManagerService: Waking up from Asleep (uid=10159, reason=WAKE_REASON_APPLICATION, details=CALLING_WAKE_LOCK)...
03-04 23:47:53.164 1645 1645 W UsageStatsService: Event reported without a package name, eventType:15
03-04 23:47:53.176 1645 3381 I chatty : uid=1000(system) Binder:1645_A expire 1 line
03-04 23:47:53.222 1645 1687 I DisplayPowerController: Blocking screen on until initial contents have been drawn.
03-04 23:47:53.234 1645 1687 D ActivityTaskManager: Top Process State changed to PROCESS_STATE_TOP
03-04 23:47:53.263 9655 9655 D android.widget.GridLayout: vertical constraints: y2-y1>=238, y2-y1<=0, y1-y0<=324 are inconsistent; permanently removing: y2-y1<=0.
03-04 23:47:53.272 3662 3681 V ULocation: onSetRequest: ProviderRequest[ON interval=+1d0h0m0s0ms] by WorkSource{1000 android}
03-04 23:47:53.272 3662 3681 V ULocation: using autoUpdate=true autoTime=86400000
03-04 23:47:53.275 3662 3710 D ULocClient: Set update interval to 86400000
03-04 23:47:53.275 3662 3710 D ULocService: setUpdateInterval[com.google.android.gms] interval: 86400000
03-04 23:47:53.275 3662 3710 D ULocClient: updateBinding - current: true, refs: 2, reqs: 1, avail: true
03-04 23:47:53.278 1973 1973 D StatusBar: disable<e i a s b H R c s > disable2<q i n >
03-04 23:47:53.279 1973 1973 D StatusBar: disable<e i a s b H R c s > disable2<q i n >
03-04 23:47:53.279 3662 3681 V ULocation: onSetRequest: ProviderRequest[ON interval=+1d0h0m0s0ms] by WorkSource{1000 android}
03-04 23:47:53.279 3662 3681 V ULocation: using autoUpdate=true autoTime=86400000
03-04 23:47:53.280 1645 1687 V DisplayPowerController: Brightness [32] reason changing to: 'manual', previous reason: 'screen_off'.
03-04 23:47:53.282 3662 3710 D ULocClient: Set update interval to 86400000
03-04 23:47:53.282 3662 3710 D ULocService: setUpdateInterval[com.google.android.gms] interval: 86400000
03-04 23:47:53.283 3662 3710 D ULocClient: updateBinding - current: true, refs: 2, reqs: 1, avail: true
03-04 23:47:53.285 1973 1973 D StatusBar: updateQsExpansionEnabled - QS Expand enabled: true
03-04 23:47:53.285 515 515 D SurfaceFlinger: Setting power mode 2 on display 0
03-04 23:47:53.285 704 772 I SDM : DisplayBase::SetDisplayState: Set state = 1, display 0
03-04 23:47:53.286 1025 9792 D [ELAN] : BRN Changed Callback Function : DPL ON
03-04 23:47:53.290 1645 1668 W Looper : Slow dispatch took 120ms android.ui h=com.android.server.am.ActivityManagerService$UiHandler c=null m=53
03-04 23:47:53.312 1973 1973 D KeyguardUpdateMonitor: onKeyguardVisibilityChanged(false)
03-04 23:47:53.315 1645 1670 I DisplayManagerService: Display device changed state: "Integrierter Bildschirm", ON
03-04 23:47:53.320 1973 1973 D StatusBar: disable<e i a s b H R c s > disable2<q i n >
03-04 23:47:53.422 1645 1687 V DisplayPowerController: Brightness [36] reason changing to: 'automatic', previous reason: 'manual'.
03-04 23:47:53.539 515 515 D SurfaceFlinger: Finished setting power mode 2 on display 0
03-04 23:47:53.544 1645 1670 I chatty : uid=1000(system) android.display expire 1 line
03-04 23:47:53.572 1645 1645 W Looper : Slow dispatch took 206ms main h=com.android.server.job.JobSchedulerService$JobHandler c=null m=1
03-04 23:47:53.573 1645 1645 W Looper : Slow delivery took 245ms main h=android.os.Handler c=com.android.server.statusbar.-$$Lambda$StatusBarManagerService$yr21OX4Hyd_XfExwnVnVIn3Jfe4@ff13470 m=0
03-04 23:47:53.584 1645 1645 V SettingsProvider: Notifying for 0: content://settings/system/screen_brightness
03-04 23:47:53.589 1645 1645 W Looper : Drained
03-04 23:47:53.603 1973 1973 D StatusBar: disable<e i a s b h!r!c s > disable2<q i n >
03-04 23:47:53.626 1645 1687 I DisplayPowerController: Unblocked screen on after 404 ms
03-04 23:47:53.630 1645 1687 W PowerManagerService: Screen on took 467 ms
03-04 23:47:53.639 9374 9374 D WM-SystemJobService: onStartJob for 8ace4118-4b99-41ee-934d-5d6361d14aa7
03-04 23:47:53.642 9374 9481 D WM-Processor: Processor: processing 8ace4118-4b99-41ee-934d-5d6361d14aa7
03-04 23:47:53.643 695 732 D audio_hw_primary: adev_set_parameters: enter: screen_state=on
03-04 23:47:53.643 3526 3526 D NotificationRepository: updateNotification() called with: list = [0]
03-04 23:47:53.643 695 732 D audio_hw_extn: audio_extn_set_anc_parameters: anc_enabled:0
03-04 23:47:53.643 695 732 D audio_hw_spkr_prot: audio_extn_fbsp_set_parameters: Speaker protection disabled
03-04 23:47:53.677 1645 1921 D ConnectivityService: maybeHandleNetworkMonitorMessage: 528386
03-04 23:47:53.678 2197 2197 D ServiceStateProvider: subId=1
03-04 23:47:53.681 9374 9374 D WM-WorkerWrapper: Starting work for de.rki.coronawarnapp.contactdiary.retention.ContactDiaryRetentionWorker
03-04 23:47:53.690 9190 9190 D CellBroadcastReceiver: onReceive Intent { act=android.intent.action.SERVICE_STATE flg=0x1000010 cmp=com.android.cellbroadcastreceiver/.CellBroadcastReceiver (has extras) }
03-04 23:47:53.705 2185 2727 D QCNEJ/WwanInfoRelay: onServiceStateChanged: dataState: 0 DDS:1 Notify service state update
03-04 23:47:53.705 2185 2727 D QCNEJ/WlanStaInfoRelay: Received action: android.net.wifi.RSSI_CHANGED
03-04 23:47:53.809 3372 3372 D NfcService: MSG_APPLY_SCREEN_STATE 4
03-04 23:47:53.809 3372 3372 I libnfc_nci: [INFO:NativeNfcManager.cpp(1767)] nfcManager_doSetScreenState: state = 4 prevScreenState= 2, discovry_param = 1
03-04 23:47:53.817 8429 8429 D Bugsnag : Received NDK message dbxyzptlk.T2.v0$a@2ee8376
03-04 23:47:53.839 3372 3566 I libnfc_nci: [INFO:NativeNfcManager.cpp(1210)] nfcManager_enableDiscovery: enter; tech_mask = 00
03-04 23:47:53.839 3372 3566 I libnfc_nci: [INFO:PowerSwitch.cpp(154)] PowerSwitch::setLevel: level=PS-FULL (1)
03-04 23:47:53.839 3372 3566 I libnfc_nci: [INFO:NativeNfcTag.cpp(1780)] nativeNfcTag_acquireRfInterfaceMutexLock: try to acquire lock
03-04 23:47:53.839 3372 3566 I libnfc_nci: [INFO:NativeNfcTag.cpp(1783)] nativeNfcTag_acquireRfInterfaceMutexLock: sRfInterfaceMutex lock
03-04 23:47:53.839 3372 3566 I libnfc_nci: [INFO:NativeNfcManager.cpp(2212)] stopPolling_rfDiscoveryDisabled: disable polling
03-04 23:47:53.839 3372 3566 I libnfc_nci: [INFO:nfa_dm_api.cc(477)] NFA_DisablePolling
03-04 23:47:53.840 3372 3584 I libnfc_nci: [INFO:nfa_sys_main.cc(77)] NFA got event 0x0107
03-04 23:47:53.840 3372 3584 I libnfc_nci: [INFO:nfa_dm_main.cc(122)] event: NFA_DM_API_DISABLE_POLLING_EVT (0x07)
03-04 23:47:53.840 3372 3584 I libnfc_nci: [INFO:nfa_dm_act.cc(1042)] nfa_dm_act_disable_polling
03-04 23:47:53.841 3372 3584 I libnfc_nci: [INFO:NativeNfcManager.cpp(258)] nfaConnectionCallback: event= 1
03-04 23:47:53.841 3372 3584 I libnfc_nci: [INFO:NativeNfcManager.cpp(273)] nfaConnectionCallback: NFA_POLL_DISABLED_EVT: status = 3
03-04 23:47:53.841 3372 3566 I libnfc_nci: [INFO:NativeNfcTag.cpp(1798)] nativeNfcTag_releaseRfInterfaceMutexLock: sRfInterfaceMutex unlock
03-04 23:47:53.841 3372 3566 I libnfc_nci: [INFO:nfa_ee_api.cc(434)] handle:<0x0>protocol_mask:<0x8>/<0x0>/<0x0><0x8><0x0><0x0>
03-04 23:47:53.842 3372 3566 I libnfc_nci: [INFO:nfa_ee_main.cc(403)] nfa_ee_find_ecb
03-04 23:47:53.842 3372 3584 I libnfc_nci: [INFO:nfa_sys_main.cc(77)] NFA got event 0x0206
03-04 23:47:53.843 3372 3584 I libnfc_nci: [INFO:nfa_ee_main.cc(641)] Event API_SET_PROTO_CFG(0x206), State: INIT_DONE(1)
03-04 23:47:53.843 3372 3584 I libnfc_nci: [INFO:RoutingManager.cpp(738)] RoutingManager::nfaEeCallback: NFA_EE_SET_PROTO_CFG_EVT; status=0x0
03-04 23:47:53.852 3372 3566 I libnfc_nci: [INFO:nfa_ee_api.cc(303)] handle:<0x0>technology_mask:<0x1>/<0x0>/<0x0><0x1><0x1><0x1>
03-04 23:47:53.853 3372 3566 I libnfc_nci: [INFO:nfa_ee_main.cc(403)] nfa_ee_find_ecb
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:nfa_sys_main.cc(77)] NFA got event 0x0204
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:nfa_ee_main.cc(641)] Event API_SET_TECH_CFG(0x204), State: INIT_DONE(1)
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(208)] nfa_ee_update_route_size nfcee_id:0x0 size_mask_proto:10 size_mask_tech:10
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:nfa_dm_main.cc(194)] flags:0x1
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:nfa_sys_ptim.cc(128)] nfa_sys_ptim_start_timer 0x740d1ce9f0
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:nfa_sys_ptim.cc(133)] ptim timer start
03-04 23:47:53.853 3372 3584 I libnfc_nci: [INFO:RoutingManager.cpp(724)] RoutingManager::nfaEeCallback: NFA_EE_SET_TECH_CFG_EVT; status=0x0
03-04 23:47:53.854 3372 3566 I libnfc_nci: [INFO:nfa_ee_api.cc(303)] handle:<0x0>technology_mask:<0x4>/<0x0>/<0x0><0x4><0x4><0x4>
03-04 23:47:53.854 3372 3566 I libnfc_nci: [INFO:nfa_ee_main.cc(403)] nfa_ee_find_ecb
03-04 23:47:53.854 3372 3584 I libnfc_nci: [INFO:nfa_sys_main.cc(77)] NFA got event 0x0204
03-04 23:47:53.854 3372 3584 I libnfc_nci: [INFO:nfa_ee_main.cc(641)] Event API_SET_TECH_CFG(0x204), State: INIT_DONE(1)
03-04 23:47:53.854 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(208)] nfa_ee_update_route_size nfcee_id:0x0 size_mask_proto:10 size_mask_tech:10
03-04 23:47:53.854 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.854 3372 3584 I libnfc_nci: [INFO:nfa_dm_main.cc(194)] flags:0x1
03-04 23:47:53.854 3372 3584 I libnfc_nci: [INFO:nfa_sys_ptim.cc(128)] nfa_sys_ptim_start_timer 0x740d1ce9f0
03-04 23:47:53.854 3372 3584 I libnfc_nci: [INFO:RoutingManager.cpp(724)] RoutingManager::nfaEeCallback: NFA_EE_SET_TECH_CFG_EVT; status=0x0
03-04 23:47:53.855 3372 3566 I libnfc_nci: [INFO:RoutingManager.cpp(313)] RoutingManager::commitRouting
03-04 23:47:53.855 3372 3566 I libnfc_nci: [INFO:nfa_ee_api.cc(803)] NFA_EeUpdateNow
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_sys_main.cc(77)] NFA got event 0x020D
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_main.cc(641)] Event API_UPDATE_NOW(0x20d), State: INIT_DONE(1)
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_sys_ptim.cc(156)] nfa_sys_ptim_stop_timer 0x740d1ce9f0
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_sys_ptim.cc(163)] ptim timer stop
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2713)] nfa_ee_rout_timeout
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2673)] ee_cfged: 0x94 ee_cfg_sts: 0x10
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2684)] 0: ecb_flags : 0x02, mask: 0x10
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2840)] nfa_ee_update_rout ee_cfg_sts:0x10
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_main.cc(641)] Event CFG_TO_NFCC(0x21b), State: INIT_DONE(1)
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2786)] last_active: 0x1
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2807)] nfa_ee_lmrt_to_nfcc --add the routing for NFCEEs!!
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 1
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(463)] nfa_ee_add_aid_route_to_ecb - No AID entries available
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x10 lmrt_size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2815)] nfa_ee_lmrt_to_nfcc --add the routing for DH!!
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 1
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(463)] nfa_ee_add_aid_route_to_ecb - No AID entries available
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2807)] nfa_ee_lmrt_to_nfcc --add the routing for NFCEEs!!
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 2
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2591)] nfa_ee_route_add_one_ecb_by_route_order - Route type - NA:- 2
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2815)] nfa_ee_lmrt_to_nfcc --add the routing for DH!!
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 2
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2591)] nfa_ee_route_add_one_ecb_by_route_order - Route type - NA:- 2
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2807)] nfa_ee_lmrt_to_nfcc --add the routing for NFCEEs!!
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 3
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(516)] nfa_ee_add_sys_code_route_to_ecb - No SC entries available
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2815)] nfa_ee_lmrt_to_nfcc --add the routing for DH!!
03-04 23:47:53.855 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 3
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(516)] nfa_ee_add_sys_code_route_to_ecb - No SC entries available
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2807)] nfa_ee_lmrt_to_nfcc --add the routing for NFCEEs!!
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 4
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2815)] nfa_ee_lmrt_to_nfcc --add the routing for DH!!
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:0, more:1, num_tlv:0,rout_type:- 4
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(388)] nfa_ee_add_proto_route_to_ecb - NFC DEP added for DH!!!
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2807)] nfa_ee_lmrt_to_nfcc --add the routing for NFCEEs!!
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:10, more:1, num_tlv:2,rout_type:- 5
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2815)] nfa_ee_lmrt_to_nfcc --add the routing for DH!!
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2560)] nfa_ee_route_add_one_ecb_by_route_order - max_len:860, cur_offset:10, more:0, num_tlv:2,rout_type:- 5
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(304)] nfa_ee_total_lmrt_size size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2606)] ee_cfg_sts:0x11 lmrt_size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2617)] nfa_ee_route_add_one_ecb_by_route_order : set routing num_tlv:4 tlv_size:20
03-04 23:47:53.856 3372 3584 I libnfc_nci: [INFO:NfcAdaptation.cc(616)] NfcAdaptation::HalWrite
03-04 23:47:53.857 729 729 D NxpExtns: find found MIFARE_READER_ENABLE=(0x1)
03-04 23:47:53.857 2197 2197 D ServiceStateProvider: subId=1
03-04 23:47:53.858 729 729 D NxpHal : NAME_MIFARE_READER_ENABLE : 1
03-04 23:47:53.858 729 729 D : sem_timedwait() succeeded
03-04 23:47:53.859 729 3590 D NxpTml : PN54X - Write requested.....
03-04 23:47:53.859 729 3590 D NxpTml : PN54X - Invoking I2C Write.....
03-04 23:47:53.866 2185 2727 D QCNEJ/WwanInfoRelay: onServiceStateChanged: dataState: 0 DDS:1 Notify service state update
03-04 23:47:53.871 9190 9190 D CellBroadcastReceiver: onReceive Intent { act=android.intent.action.SERVICE_STATE flg=0x1000010 cmp=com.android.cellbroadcastreceiver/.CellBroadcastReceiver (has extras) }
03-04 23:47:53.962 9374 9480 D WM-WorkerWrapper: de.rki.coronawarnapp.contactdiary.retention.ContactDiaryRetentionWorker returned a Success {mOutputData=Data {}} result.
03-04 23:47:53.966 9374 9480 I WM-WorkerWrapper: Worker result SUCCESS for Work [ id=8ace4118-4b99-41ee-934d-5d6361d14aa7, tags={ de.rki.coronawarnapp.contactdiary.retention.ContactDiaryRetentionWorker } ]
03-04 23:47:53.971 9374 9374 D WM-Processor: Processor 8ace4118-4b99-41ee-934d-5d6361d14aa7 executed; reschedule = false
03-04 23:47:53.972 9374 9374 D WM-SystemJobService: 8ace4118-4b99-41ee-934d-5d6361d14aa7 executed on JobScheduler
03-04 23:47:53.982 9374 9480 D WM-GreedyScheduler: Cancelling work ID 8ace4118-4b99-41ee-934d-5d6361d14aa7
03-04 23:47:53.994 729 3590 D NxpTml : _i2c_write() errno : 5
03-04 23:47:53.994 729 3590 D NxpTml : PN54X - Error in I2C Write.....
03-04 23:47:53.994 729 3590 D NxpTml : PN54X - Posting Fresh Write message.....
03-04 23:47:53.994 729 3590 D NxpTml : PN54X - Tml Writer Thread Running................
03-04 23:47:53.994 729 3592 E NxpHal : write error status = 0x1ff
03-04 23:47:53.994 729 729 D NxpHal : write_unlocked failed - PN54X Maybe in Standby Mode - Retry
03-04 23:47:54.000 729 3590 D NxpTml : PN54X - Write requested.....
03-04 23:47:54.000 729 3590 D NxpTml : PN54X - Invoking I2C Write.....
03-04 23:47:54.002 729 3589 D NxpTml : PN54X - I2C Read successful.....len = 4
03-04 23:47:54.002 729 3589 D NxpTml : Delay Read if write thread is busy
03-04 23:47:54.002 729 3590 D NxpNciX : len = 25 => 21011600040103000104010300010500030001000003000102
03-04 23:47:54.002 729 3590 D NxpTml : PN54X - I2C Write successful.....
03-04 23:47:54.002 729 3590 D NxpTml : PN54X - Posting Fresh Write message.....
03-04 23:47:54.002 729 3590 D NxpTml : PN54X - Tml Writer Thread Running................
03-04 23:47:54.003 729 3592 D NxpHal : write successful status = 0x0
03-04 23:47:54.004 9374 9480 D WM-SystemJobScheduler: Scheduling work ID 8ace4118-4b99-41ee-934d-5d6361d14aa7 Job ID 1444
03-04 23:47:54.004 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2862)] nfa_ee_update_rout ee_cfg_sts:0x10 ee_cfged:0x14
03-04 23:47:54.005 729 3589 D NxpTml : PN54X - Posting read message.....
03-04 23:47:54.005 729 3589 D NxpNciR : len = 4 <= 41010100
03-04 23:47:54.006 729 3592 D NxpHal : read successful status = 0x0
03-04 23:47:54.007 729 3589 D NxpTml : PN54X - Read requested.....
03-04 23:47:54.007 3372 3584 I libnfc_nci: [INFO:nfc_ncif.cc(417)] NFC received rsp gid:1
03-04 23:47:54.007 729 3589 D NxpTml : PN54X - Invoking I2C Read.....
03-04 23:47:54.007 3372 3584 I libnfc_nci: [INFO:nfa_dm_act.cc(268)] NFC_SET_ROUTING_REVT(0x500a)
03-04 23:47:54.007 3372 3584 I libnfc_nci: [INFO:nfa_ee_main.cc(359)] nfa_ee_proc_evt: event=0x500a int_event:0x218
03-04 23:47:54.007 3372 3584 I libnfc_nci: [INFO:nfa_ee_main.cc(641)] Event NCI_WAIT_RSP(0x218), State: INIT_DONE(1)
03-04 23:47:54.007 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2248)] ee_wait_evt:0x30 wait_rsp:1
03-04 23:47:54.007 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2221)] nfa_ee_report_update_evt ee_wait_evt:0x30 wait_rsp:0
03-04 23:47:54.007 3372 3584 I libnfc_nci: [INFO:RoutingManager.cpp(837)] RoutingManager::nfaEeCallback: NFA_EE_UPDATED_EVT
03-04 23:47:54.007 3372 3566 I libnfc_nci: [INFO:NativeNfcManager.cpp(2082)] startRfDiscovery: is start=1
03-04 23:47:54.008 3372 3566 I libnfc_nci: [INFO:NativeNfcTag.cpp(1780)] nativeNfcTag_acquireRfInterfaceMutexLock: try to acquire lock
03-04 23:47:54.008 3372 3566 I libnfc_nci: [INFO:NativeNfcTag.cpp(1783)] nativeNfcTag_acquireRfInterfaceMutexLock: sRfInterfaceMutex lock
03-04 23:47:54.008 3372 3566 I libnfc_nci: [INFO:nfa_dm_api.cc(691)] NFA_StartRfDiscovery
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_sys_main.cc(77)] NFA got event 0x010E
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_dm_main.cc(122)] event: NFA_DM_API_START_RF_DISCOVERY_EVT (0x0e)
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_dm_act.cc(1230)] nfa_dm_act_start_rf_discovery
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(884)] nfa_dm_start_rf_discover
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2484)] 1
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_ee_act.cc(2508)] 0x0, 0x0, 0x0, 0x0
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(1012)] nfa_dm_cb.disc_cb.entry[0].selected_disc_mask = 0x40000
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(1050)] dm_disc_mask = 0x40000
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(280)] tech_proto_mask = 0x00040000
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:nfa_dm_main.cc(222)] nfa_dm_check_set_config
03-04 23:47:54.008 3372 3584 I libnfc_nci: [INFO:NfcAdaptation.cc(616)] NfcAdaptation::HalWrite
03-04 23:47:54.008 729 729 D NxpExtns: find found MIFARE_READER_ENABLE=(0x1)
03-04 23:47:54.008 729 729 D NxpHal : NAME_MIFARE_READER_ENABLE : 1
03-04 23:47:54.008 729 729 D : sem_timedwait() succeeded
03-04 23:47:54.009 729 3590 D NxpTml : PN54X - Write requested.....
03-04 23:47:54.009 729 3590 D NxpTml : PN54X - Invoking I2C Write.....
03-04 23:47:54.010 729 3590 D NxpNciX : len = 10 => 20020702320120500100
03-04 23:47:54.010 729 3590 D NxpTml : PN54X - I2C Write successful.....
03-04 23:47:54.010 729 3590 D NxpTml : PN54X - Posting Fresh Write message.....
03-04 23:47:54.010 729 3590 D NxpTml : PN54X - Tml Writer Thread Running................
03-04 23:47:54.010 729 3592 D NxpHal : write successful status = 0x0
03-04 23:47:54.011 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(370)] nfa_dm_set_total_duration
03-04 23:47:54.011 3372 3584 I libnfc_nci: [INFO:nfa_dm_main.cc(222)] nfa_dm_check_set_config
03-04 23:47:54.011 3372 3584 I libnfc_nci: [INFO:nfc_main.cc(888)] NFC_DiscoveryStart
03-04 23:47:54.011 3372 3584 I libnfc_nci: [INFO:nfc_main.cc(908)] NFC_DiscoveryStart status: 0xe3
03-04 23:47:54.016 729 3589 D NxpTml : PN54X - I2C Read successful.....len = 5
03-04 23:47:54.016 729 3589 D NxpTml : PN54X - Posting read message.....
03-04 23:47:54.016 729 3589 D NxpNciR : len = 5 <= 4002020000
03-04 23:47:54.017 729 3592 D NxpHal : read successful status = 0x0
03-04 23:47:54.017 729 3592 D NxpHal : phNxpNciHal_print_res_status: response status =STATUS_OK
03-04 23:47:54.017 3372 3584 I libnfc_nci: [INFO:nfc_ncif.cc(417)] NFC received rsp gid:0
03-04 23:47:54.017 3372 3584 I libnfc_nci: [INFO:nci_hrcv.cc(62)] nci_proc_core_rsp opcode:0x2
03-04 23:47:54.017 729 3589 D NxpTml : PN54X - Read requested.....
03-04 23:47:54.017 3372 3584 I libnfc_nci: [INFO:nfa_dm_act.cc(268)] NFC_SET_CONFIG_REVT(0x5002)
03-04 23:47:54.017 729 3589 D NxpTml : PN54X - Invoking I2C Read.....
03-04 23:47:54.017 3372 3584 I libnfc_nci: [INFO:NfcAdaptation.cc(657)] NfcAdaptation::HalPrediscover
03-04 23:47:54.018 3372 3584 I libnfc_nci: [INFO:NfcAdaptation.cc(616)] NfcAdaptation::HalWrite
03-04 23:47:54.018 729 729 D NxpExtns: find found MIFARE_READER_ENABLE=(0x1)
03-04 23:47:54.018 729 729 D NxpHal : NAME_MIFARE_READER_ENABLE : 1
03-04 23:47:54.018 729 729 D NxpHal : > Polling Loop Started
03-04 23:47:54.018 729 729 D : sem_timedwait() succeeded
03-04 23:47:54.018 729 3590 D NxpTml : PN54X - Write requested.....
03-04 23:47:54.018 729 3590 D NxpTml : PN54X - Invoking I2C Write.....
03-04 23:47:54.020 729 3590 D NxpNciX : len = 6 => 210303018001
03-04 23:47:54.020 729 3590 D NxpTml : PN54X - I2C Write successful.....
03-04 23:47:54.020 729 3590 D NxpTml : PN54X - Posting Fresh Write message.....
03-04 23:47:54.020 729 3590 D NxpTml : PN54X - Tml Writer Thread Running................
03-04 23:47:54.020 729 3589 D NxpTml : PN54X - I2C Read successful.....len = 4
03-04 23:47:54.020 729 3592 D NxpHal : write successful status = 0x0
03-04 23:47:54.020 729 3589 D NxpTml : PN54X - Posting read message.....
03-04 23:47:54.020 729 3589 D NxpNciR : len = 4 <= 41030100
03-04 23:47:54.020 729 3592 D NxpHal : read successful status = 0x0
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:nfc_ncif.cc(417)] NFC received rsp gid:1
03-04 23:47:54.021 729 3589 D NxpTml : PN54X - Read requested.....
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(3030)] returning TRUE
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(694)] event:0x4000
03-04 23:47:54.021 729 3589 D NxpTml : PN54X - Invoking I2C Read.....
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(2518)] state: IDLE (0), event: DISCOVER_RSP(1) disc_flags: 0x31
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(1685)] old_state: IDLE (0), new_state: DISCOVERY (1) disc_flags: 0x11
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:NativeNfcManager.cpp(258)] nfaConnectionCallback: event= 30
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:NativeNfcManager.cpp(283)] nfaConnectionCallback: NFA_RF_DISCOVERY_STARTED_EVT: status = 0
03-04 23:47:54.021 3372 3584 I libnfc_nci: [INFO:nfa_dm_discover.cc(2571)] new state: DISCOVERY (1), disc_flags: 0x1
03-04 23:47:54.021 3372 3566 I libnfc_nci: [INFO:NativeNfcTag.cpp(1798)] nativeNfcTag_releaseRfInterfaceMutexLock: sRfInterfaceMutex unlock
03-04 23:47:54.021 3372 3566 I libnfc_nci: [INFO:PowerSwitch.cpp(258)] PowerSwitch::setModeOn(activated=0x1) : mCurrActivity=0x1
03-04 23:47:54.021 3372 3566 I libnfc_nci: [INFO:NativeNfcManager.cpp(1285)] nfcManager_enableDiscovery: exit
03-04 23:47:54.023 9374 9480 D WM-Processor: Processor stopping background work 8ace4118-4b99-41ee-934d-5d6361d14aa7
03-04 23:47:54.023 9374 9480 D WM-Processor: WorkerWrapper could not be found for 8ace4118-4b99-41ee-934d-5d6361d14aa7
03-04 23:47:54.024 9374 9480 D WM-StopWorkRunnable: StopWorkRunnable for 8ace4118-4b99-41ee-934d-5d6361d14aa7; Processor.stopWork = false
03-04 23:47:54.322 1973 2107 D ImageWallpaper: finishRendering, preserve=false
03-04 23:47:54.436 932 932 D NuPlayerDriver: stop(0xeaa5c820)
03-04 23:47:54.459 9655 9655 D android.widget.GridLayout: vertical constraints: y2-y1>=238, y2-y1<=0, y1-y0<=324 are inconsistent; permanently removing: y2-y1<=0.
03-04 23:47:54.514 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: initPlayout(sampleRate=48000, channels=1, bufferSizeFactor=1.0)
03-04 23:47:54.514 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: byteBuffer.capacity: 960
03-04 23:47:54.515 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: minBufferSizeInBytes: 3848
03-04 23:47:54.515 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: createAudioTrackOnLollipopOrHigher
03-04 23:47:54.515 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: nativeOutputSampleRate: 48000
03-04 23:47:54.517 695 732 D audio_hw_primary: adev_get_parameters:voip_out_stream_count
03-04 23:47:54.517 695 732 D audio_hw_spkr_prot: audio_extn_fbsp_get_parameters: Speaker protection disabled
03-04 23:47:54.517 695 732 D soundtrigger: audio_extn_sound_trigger_get_parameters input string<voip_out_stream_count=>
03-04 23:47:54.517 695 732 D soundtrigger: extract_sm_handle input string <voip_out_stream_count=> param string <voip_out_stream_count=>
03-04 23:47:54.517 695 732 D audio_hw_extn: audio_extn_get_parameters: returns
03-04 23:47:54.517 695 732 D audio_hw_primary: adev_get_parameters: exit: returns - voip_out_stream_count=0
03-04 23:47:54.517 755 9544 I hash_map_utils: key: 'voip_out_stream_count' value: ''
03-04 23:47:54.518 695 732 D audio_hw_primary: adev_get_parameters:voip_sample_rate
03-04 23:47:54.518 695 732 D audio_hw_spkr_prot: audio_extn_fbsp_get_parameters: Speaker protection disabled
03-04 23:47:54.518 695 732 D soundtrigger: audio_extn_sound_trigger_get_parameters input string<voip_sample_rate=>
03-04 23:47:54.518 695 732 D soundtrigger: extract_sm_handle input string <voip_sample_rate=> param string <voip_sample_rate=>
03-04 23:47:54.518 695 732 D audio_hw_extn: audio_extn_get_parameters: returns
03-04 23:47:54.518 695 732 D audio_hw_primary: adev_get_parameters: exit: returns - voip_sample_rate=0
03-04 23:47:54.518 755 9544 I hash_map_utils: key: 'voip_sample_rate' value: ''
03-04 23:47:54.519 755 9544 D AudioPolicyManagerCustom: Set VoIP and Direct output flags for PCM format
03-04 23:47:54.519 695 732 D audio_hw_primary: adev_get_parameters:vr_audio_mode_on
03-04 23:47:54.519 695 732 I audio_hw_primary: getting vr mode to 0
03-04 23:47:54.519 695 732 D audio_hw_primary: adev_get_parameters: exit: returns - vr_audio_mode_on=false
03-04 23:47:54.519 755 9544 I hash_map_utils: key: 'vr_audio_mode_on' value: ''
03-04 23:47:54.520 755 9544 I AudioPolicyManagerCustom: VR mode is 0, switch to primary output if request is for fast|raw
03-04 23:47:54.520 755 9544 D AudioFlinger: Client defaulted notificationFrames to 962 for frameCount 1924
03-04 23:47:54.522 755 9544 D AF::TrackHandle: OpPlayAudio: track:63 usage:2 not muted
03-04 23:47:54.528 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: AudioTrack: session ID: 481, channels: 1, sample rate: 48000, max gain: 1.0
03-04 23:47:54.529 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: AudioTrack: buffer size in frames: 1924
03-04 23:47:54.529 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: AudioTrack: buffer capacity in frames: 1924
03-04 23:47:54.529 9655 9766 I org.webrtc.Logging: WebRtcAudioTrack: startPlayout
03-04 23:47:54.565 695 733 D audio_hw_primary: out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=2
03-04 23:47:54.565 695 733 D audio_hw_primary: select_devices for use case (low-latency-playback)
03-04 23:47:54.565 695 733 D audio_hw_extn: audio_extn_set_anc_parameters: anc_enabled:0
03-04 23:47:54.565 695 733 D audio_hw_spkr_prot: audio_extn_fbsp_set_parameters: Speaker protection disabled
03-04 23:47:54.570 9655 9812 I org.webrtc.Logging: WebRtcAudioTrack: AudioTrackThread@[name=AudioTrackJavaThread, id=942]
03-04 23:47:54.583 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: enableBuiltInAEC(true)
03-04 23:47:54.583 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: setAEC(true)
03-04 23:47:54.583 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseAcousticEchoCanceler: true
03-04 23:47:54.583 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: enableBuiltInNS(true)
03-04 23:47:54.583 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: setNS(true)
03-04 23:47:54.584 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseNoiseSuppressor: true
03-04 23:47:54.606 612 9817 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.606 612 9823 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.608 612 9822 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.610 612 9820 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.611 932 9778 D AudioTrack: getTimestamp_l(31): device stall time corrected using current time 362940475216
03-04 23:47:54.617 612 9826 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.617 612 9825 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.667 612 9834 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.668 612 9838 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.670 612 9832 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.686 612 9837 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.687 612 9839 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.688 612 9842 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.691 612 9851 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.693 612 9853 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.693 612 9852 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.697 612 9855 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.700 612 9854 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.702 612 9856 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.706 612 9858 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.708 612 9857 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.715 612 9860 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.716 612 9859 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.716 612 9861 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:54.719 612 9862 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:47:56.343 1645 1666 I chatty : uid=1000(system) Binder:1645_2 expire 1 line
03-04 23:47:56.369 1055 2057 I LOWI-8.6.0.75: [LOWI-Scan] lowi_close_record:Scan done in 403729ms, 21 APs in scan results
03-04 23:47:56.375 1055 1077 I LOWI-8.6.0.75: [LOWIUtils] responseToOutPostcard - TO: FreeWifiScanObserver, FROM: LOWI-SERVER, RESP: LOWI_ASYNC_DISCOVERY_SCAN_RESULTS
03-04 23:47:56.383 703 741 I LocSvc_api_v02: ---> locClientSendReq line 2345 QMI_LOC_INJECT_WIFI_AP_DATA_REQ_V02
03-04 23:47:56.386 703 1228 I LocSvc_ApiV02: <--- globalRespCb line 192 QMI_LOC_INJECT_WIFI_AP_DATA_REQ_V02
03-04 23:47:56.559 612 1008 I netd : trafficSwapActiveStatsMap() <40.89ms>
03-04 23:47:56.601 612 1008 I netd : tetherGetStats() <26.47ms>
03-04 23:47:56.673 612 612 I Binder:612_4: type=1400 audit(0.0:93): avc: denied { associate } for name="globalAlert" scontext=u:object_r:proc_net:s0 tcontext=u:object_r:proc:s0 tclass=filesystem permissive=1
03-04 23:47:56.678 612 1008 I netd : bandwidthSetGlobalAlert(1073741) <1.79ms>
03-04 23:47:57.796 1973 1973 V StatusBar: mStatusBarWindow: com.android.systemui.statusbar.phone.StatusBarWindowView{1ac257c V.E...... ........ 0,0-1080,65} canPanelBeCollapsed(): false
03-04 23:47:59.422 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: enableBuiltInAEC(true)
03-04 23:47:59.422 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: setAEC(true)
03-04 23:47:59.423 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseAcousticEchoCanceler: true
03-04 23:47:59.423 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: enableBuiltInNS(true)
03-04 23:47:59.423 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: setNS(true)
03-04 23:47:59.424 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseNoiseSuppressor: true
03-04 23:47:59.424 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: initRecording(sampleRate=48000, channels=1)
03-04 23:47:59.426 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: byteBuffer.capacity: 960
03-04 23:47:59.426 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: AudioRecord.getMinBufferSize: 3840
03-04 23:47:59.427 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: bufferSizeInBytes: 7680
03-04 23:47:59.438 9655 9721 D avs AudioRouter: GetAudioRoute() Speaker
03-04 23:47:59.442 9655 9721 D avs AudioRouter: GetAudioRoute() Speaker
03-04 23:47:59.443 9655 9721 D avs AudioRouter: EnableEarpiece
03-04 23:47:59.447 9655 9721 D avs AudioRouter: GetAudioRoute() Speaker
03-04 23:47:59.448 755 9544 D AudioPolicyManagerCustom: setForceUse() usage 0, config 0, mPhoneState 0
03-04 23:47:59.453 9655 9721 D avs AudioRouter: GetAudioRoute() Earpiece
03-04 23:47:59.456 9655 9721 I avs AudioRouter: OnStartingCall: incall=false
03-04 23:47:59.456 9655 9721 I avs AudioRouter: OnStartingCall btdev=null
03-04 23:47:59.457 9655 9721 W AudioManager: Use of stream types is deprecated for operations other than volume control
03-04 23:47:59.457 9655 9721 W AudioManager: See the documentation of requestAudioFocus() for what to use instead with android.media.AudioAttributes to qualify your playback use case
03-04 23:47:59.458 1645 5904 I chatty : uid=1000(system) Binder:1645_13 expire 2 lines
03-04 23:47:59.459 9655 9721 W AudioManager: Use of stream types is deprecated for operations other than volume control
03-04 23:47:59.459 9655 9721 W AudioManager: See the documentation of requestAudioFocus() for what to use instead with android.media.AudioAttributes to qualify your playback use case
03-04 23:47:59.585 695 733 D audio_hw_primary: out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=1
03-04 23:47:59.587 695 733 D audio_hw_primary: select_devices for use case (low-latency-playback)
03-04 23:47:59.587 695 733 D audio_hw_primary: select_devices: out_snd_device(1: handset) in_snd_device(0: )
03-04 23:47:59.587 695 733 D audio_hw_primary: disable_audio_route: reset and update mixer path: low-latency-playback
03-04 23:47:59.614 9655 9668 I com.wire: Background concurrent copying GC freed 54288(3642KB) AllocSpace objects, 1(68KB) LOS objects, 49% free, 16MB/32MB, paused 88us total 120.266ms
03-04 23:47:59.625 695 733 D soundtrigger: audio_extn_sound_trigger_update_stream_status: uc_info->id 1 of type 0 for Event 2, with Raise=0
03-04 23:47:59.625 695 733 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(0) new_snd_devices(0)
03-04 23:47:59.625 695 733 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 2
03-04 23:47:59.625 695 733 D hardware_info: hw_info_append_hw_type : device_name = speaker
03-04 23:47:59.625 695 733 D audio_hw_primary: disable_snd_device: snd_device(2: speaker)
03-04 23:47:59.625 695 733 D msm8916_platform: platform_split_snd_device: snd_device(2) num devices(0) new_snd_devices(0)
03-04 23:47:59.625 695 733 I soundtrigger: audio_extn_sound_trigger_update_device_status: device 0x2 of type 0 for Event 0, with Raise=0
03-04 23:47:59.625 695 733 I msm8916_platform: platform_check_and_set_codec_backend_cfg:becf: afe: bitwidth 16, samplerate 48000 channels 2, backend_idx 0 usecase = 1 device (handset)
03-04 23:47:59.625 695 733 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(1) new_snd_devices(0)
03-04 23:47:59.625 695 733 I msm8916_platform: platform_check_and_set_codec_backend_cfg: becf: new_snd_devices[0] is handset
03-04 23:47:59.625 695 733 I msm8916_platform: platform_check_codec_backend_cfg:becf: afe: Codec selected backend: 0 current bit width: 16 sample rate: 48000 channels: 2 usecase 1 device (handset)
03-04 23:47:59.625 695 733 D msm8916_platform: platform_check_codec_backend_cfg:becf: afe: playback on codec device not supporting native playback set default Sample Rate(48k)
03-04 23:47:59.625 695 733 I msm8916_platform: platform_check_codec_backend_cfg:becf: afe: Codec selected backend: 0 updated bit width: 16 sample rate: 48000 channels: 2
03-04 23:47:59.625 695 733 D audio_hw_primary: check_usecases_codec_backend:becf: force routing 0
03-04 23:47:59.625 695 733 D audio_hw_primary: check_usecases_codec_backend:becf: (65) check_usecases curr device: handset, usecase device:speaker backends match 1
03-04 23:47:59.625 695 733 D audio_hw_primary: check_usecases_codec_backend:becf: check_usecases num.of Usecases to switch 0
03-04 23:47:59.625 695 733 D hardware_info: hw_info_append_hw_type : device_name = handset
03-04 23:47:59.625 695 733 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:47:59.625 695 733 D audio_hw_primary: enable_snd_device: snd_device(1: handset)
03-04 23:47:59.625 695 733 I soundtrigger: audio_extn_sound_trigger_update_device_status: device 0x1 of type 0 for Event 1, with Raise=0
03-04 23:47:59.625 695 733 D audio_route: Apply path: handset
03-04 23:47:59.629 695 733 D soundtrigger: audio_extn_sound_trigger_update_stream_status: uc_info->id 1 of type 0 for Event 3, with Raise=0
03-04 23:47:59.629 695 733 D audio_hw_utils: audio_extn_utils_send_app_type_cfg: usecase->out_snd_device handset
03-04 23:47:59.629 695 733 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:47:59.629 695 733 D audio_hw_utils: audio_extn_btsco_get_sample_rate:Not a BT SCO device, need not update sampling rate
03-04 23:47:59.629 695 733 I audio_hw_utils: send_app_type_cfg_for_device PLAYBACK app_type 69937, acdb_dev_id 7, sample_rate 48000, snd_device_be_idx 2
03-04 23:47:59.630 695 733 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(1) new_snd_devices(0)
03-04 23:47:59.630 695 733 D audio_hw_utils: audio_extn_btsco_get_sample_rate:Not a BT SCO device, need not update sampling rate
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> send_audio_cal, acdb_id = 7, path = 0, app id = 0x11131, sample rate = 48000, afe_sample_rate = 48000
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> send_asm_topology
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TOPOLOGY_ID
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> send_adm_topology
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TOPOLOGY_ID
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> send_audtable
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE_SIZE
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> AUDIO_SET_AUDPROC_CAL cal_type[11] acdb_id[7] app_type[69937]
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> send_audvoltable
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE_SIZE
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE, vol index 0
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> AUDIO_SET_VOL_CAL cal type = 12
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TABLE_SIZE
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> send_audstrmtable
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TABLE_V2
03-04 23:47:59.630 695 733 D ACDB-LOADER: ACDB -> audstrm_cal->cal_type.cal_data.cal_size = 16
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> send_afe_topology
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_TOPOLOGY_ID
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> GET_AFE_TOPOLOGY_ID for adcd_id 7, Topology Id 112fc
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> send_afe_cal
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE
03-04 23:47:59.631 695 733 D : Failed to fetch the lookup information of the device 00000007
03-04 23:47:59.631 695 733 D ACDB-LOADER: Error: ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE Returned = -19
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE
03-04 23:47:59.631 695 733 D : Failed to fetch the lookup information of the device 00000007
03-04 23:47:59.631 695 733 D ACDB-LOADER: Error: ACDB AFE returned = -19
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> AUDIO_SET_AFE_CAL cal_type[16] acdb_id[7]
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> send_hw_delay : acdb_id = 7 path = 0
03-04 23:47:59.631 695 733 D ACDB-LOADER: ACDB -> ACDB_AVSYNC_INFO: ACDB_CMD_GET_DEVICE_PROPERTY
03-04 23:47:59.631 695 733 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:47:59.631 695 733 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 1
03-04 23:47:59.631 695 733 D audio_hw_primary: enable_audio_route: apply mixer and update path: low-latency-playback handset
03-04 23:47:59.631 695 733 D audio_route: Apply path: low-latency-playback handset
03-04 23:47:59.687 695 733 D audio_hw_primary: select_devices: done
03-04 23:47:59.688 695 733 D audio_hw_extn: audio_extn_set_anc_parameters: anc_enabled:0
03-04 23:47:59.688 695 733 D audio_hw_spkr_prot: audio_extn_fbsp_set_parameters: Speaker protection disabled
03-04 23:47:59.688 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:47:59.688 695 8642 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 1
03-04 23:47:59.697 695 733 D audio_hw_primary: adev_open_input_stream: enter: sample_rate(48000) channel_mask(0x10) devices(0x80000004) stream_handle(0xef851e00) io_handle(62) source(7) format 1
03-04 23:47:59.697 695 733 D compress_voip: voice_extn_compress_voip_pcm_prop_check: VoIP PCM property is enabled
03-04 23:47:59.697 695 733 D compress_voip: voice_extn_compress_voip_open_input_stream: enter
03-04 23:47:59.697 695 733 D compress_voip: voip_set_mode: enter, format=1
03-04 23:47:59.697 695 733 D compress_voip: voip_set_mode: Derived mode = 12
03-04 23:47:59.698 695 733 W audio_hw_utils: audio_extn_utils_update_stream_input_app_type_cfg: App type could not be selected. Falling back to default
03-04 23:47:59.706 755 9870 I AudioFlinger: AudioFlinger's thread 0x7c47c5d540 tid=9870 ready to run
03-04 23:47:59.706 695 733 D audio_hw_primary: in_standby: enter: stream (0xef851e00) usecase(38: compress-voip-call)
03-04 23:47:59.708 695 733 D audio_hw_primary: adev_set_mode: mode 3
03-04 23:47:59.708 695 732 D audio_hw_primary: in_standby: enter: stream (0xef851e00) usecase(38: compress-voip-call)
03-04 23:47:59.715 695 732 W EffectHAL: Effect 0xee1001b0 command SET_CONFIG returned status: Invalid argument
03-04 23:47:59.715 1645 8452 I chatty : uid=1000(system) Binder:1645_16 expire 1 line
03-04 23:47:59.717 755 3878 D AudioPolicyManagerCustom: setPhoneState() state 3
03-04 23:47:59.779 695 733 D audio_hw_primary: out_set_parameters: enter: usecase(1: low-latency-playback) kvpairs: routing=1
03-04 23:47:59.781 695 733 D audio_hw_primary: select_devices for use case (low-latency-playback)
03-04 23:47:59.781 695 733 D audio_hw_extn: audio_extn_set_anc_parameters: anc_enabled:0
03-04 23:47:59.782 695 733 D audio_hw_spkr_prot: audio_extn_fbsp_set_parameters: Speaker protection disabled
03-04 23:47:59.814 695 733 D audio_hw_primary: out_set_parameters: enter: usecase(12: audio-ull-playback) kvpairs: routing=1
03-04 23:47:59.864 695 732 D audio_hw_primary: out_set_parameters: enter: usecase(0: deep-buffer-playback) kvpairs: routing=1
03-04 23:47:59.875 695 733 W EffectHAL: Effect 0xee1001b0 command SET_CONFIG returned status: Invalid argument
03-04 23:47:59.876 695 733 W EffectHAL: Effect 0xef8757c0 command SET_CONFIG returned status: Invalid argument
03-04 23:47:59.889 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: enable(audioSession=489)
03-04 23:47:59.901 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseAcousticEchoCanceler: true
03-04 23:47:59.902 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: AcousticEchoCanceler: was enabled, enable: true, is now: enabled
03-04 23:47:59.909 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: canUseNoiseSuppressor: true
03-04 23:47:59.909 9655 9766 I org.webrtc.Logging: WebRtcAudioEffects: NoiseSuppressor: was enabled, enable: true, is now: enabled
03-04 23:47:59.910 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: AudioRecord: session ID: 489, channels: 1, sample rate: 48000
03-04 23:47:59.910 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: AudioRecord: buffer size in frames: 3840
03-04 23:47:59.912 9655 9766 I org.webrtc.Logging: WebRtcAudioRecord: startRecording
03-04 23:47:59.932 695 732 D audio_hw_primary: in_set_parameters: enter: kvpairs=bottom=;input_source=7;routing=-2147483644
03-04 23:47:59.942 755 1755 I SoundTriggerHwService::Module: onCallbackEvent no clients
03-04 23:47:59.943 695 732 W StreamHAL: Error from HAL stream in function set_microphone_direction: Function not implemented
03-04 23:47:59.948 695 733 W StreamHAL: Error from HAL stream in function set_microphone_field_dimension: Function not implemented
03-04 23:47:59.948 695 9871 D compress_voip: voice_extn_compress_voip_start_input_stream: enter
03-04 23:47:59.948 695 9871 D compress_voip: voip_start_call: enter
03-04 23:47:59.949 695 9871 D audio_hw_primary: select_devices for use case (compress-voip-call)
03-04 23:47:59.949 695 9871 D audio_hw_primary: select_devices: out_snd_device(16: voice-handset) in_snd_device(95: voice-dmic-ef)
03-04 23:47:59.949 695 9871 I msm8916_platform: platform_check_and_set_codec_backend_cfg:becf: afe: bitwidth 16, samplerate 48000 channels 2, backend_idx 0 usecase = 38 device (voice-handset)
03-04 23:47:59.949 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(16) num devices(1) new_snd_devices(0)
03-04 23:47:59.949 695 9871 I msm8916_platform: platform_check_and_set_codec_backend_cfg: becf: new_snd_devices[0] is voice-handset
03-04 23:47:59.949 695 9871 I msm8916_platform: platform_check_codec_backend_cfg:becf: afe: Codec selected backend: 0 current bit width: 16 sample rate: 48000 channels: 2 usecase 38 device (voice-handset)
03-04 23:47:59.949 695 9871 W msm8916_platform: platform_check_codec_backend_cfg:becf: afe:Use default bw and sr for voice/voip calls
03-04 23:47:59.949 695 9871 D msm8916_platform: platform_check_codec_backend_cfg:becf: afe: playback on codec device not supporting native playback set default Sample Rate(48k)
03-04 23:47:59.949 695 9871 I msm8916_platform: platform_check_codec_backend_cfg:becf: afe: Codec selected backend: 0 updated bit width: 16 sample rate: 48000 channels: 2
03-04 23:47:59.949 695 9871 D audio_hw_primary: check_usecases_codec_backend:becf: force routing 0
03-04 23:47:59.949 695 9871 D audio_hw_primary: check_usecases_codec_backend:becf: (65) check_usecases curr device: voice-handset, usecase device:handset backends match 1
03-04 23:47:59.949 695 9871 D audio_hw_primary: check_usecases_codec_backend:becf: check_usecases (low-latency-playback) is active on (handset) - disabling ..
03-04 23:47:59.949 695 9871 D audio_hw_primary: disable_audio_route: reset and update mixer path: low-latency-playback handset
03-04 23:47:59.956 9655 9872 I org.webrtc.Logging: WebRtcAudioRecord: AudioRecordThread@[name=AudioRecordJavaThread, id=1040]
03-04 23:47:59.968 1973 2309 I vol.Events: writeEvent level_changed STREAM_MUSIC 5
03-04 23:47:59.969 755 3878 D AudioPolicyManagerCustom: setForceUse() usage 7, config 0, mPhoneState 3
03-04 23:47:59.980 9655 9721 D avs AudioRouter: GetAudioRoute() Earpiece
03-04 23:47:59.995 695 9871 D soundtrigger: audio_extn_sound_trigger_update_stream_status: uc_info->id 1 of type 0 for Event 2, with Raise=0
03-04 23:47:59.995 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:47:59.995 695 9871 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 1
03-04 23:47:59.995 695 9871 E msm8916_platform: platform_check_backends_match: Invalid snd_device =
03-04 23:47:59.995 695 9871 D audio_hw_primary: check_usecases_codec_backend:becf: (65) check_usecases curr device: voice-handset, usecase device: backends match 0
03-04 23:47:59.995 695 9871 D audio_hw_primary: check_usecases_codec_backend:becf: check_usecases num.of Usecases to switch 1
03-04 23:47:59.995 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:47:59.995 695 9871 D hardware_info: hw_info_append_hw_type : device_name = handset
03-04 23:47:59.995 695 9871 D audio_hw_primary: disable_snd_device: snd_device(1: handset)
03-04 23:47:59.995 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:48:00.000 932 932 D NuPlayerDriver: NuPlayerDriver(0xeaa5c780) created, clientPid(9655)
03-04 23:48:00.006 695 9871 I soundtrigger: audio_extn_sound_trigger_update_device_status: device 0x1 of type 0 for Event 0, with Raise=0
03-04 23:48:00.006 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(1) num devices(0) new_snd_devices(0)
03-04 23:48:00.006 695 9871 D hardware_info: hw_info_append_hw_type : device_name = voice-handset
03-04 23:48:00.006 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(16) num devices(0) new_snd_devices(0)
03-04 23:48:00.006 695 9871 D audio_hw_primary: enable_snd_device: snd_device(16: voice-handset)
03-04 23:48:00.006 695 9871 I soundtrigger: audio_extn_sound_trigger_update_device_status: device 0x10 of type 0 for Event 1, with Raise=0
03-04 23:48:00.006 695 9871 D audio_route: Apply path: voice-handset
03-04 23:48:00.010 932 932 I Codec2Client: Creating a Codec2 client to service "software"
03-04 23:48:00.011 695 9871 D audio_hw_primary: check_usecases_codec_backend:becf: enabling usecase (low-latency-playback) on (voice-handset)
03-04 23:48:00.012 695 9871 D soundtrigger: audio_extn_sound_trigger_update_stream_status: uc_info->id 1 of type 0 for Event 3, with Raise=0
03-04 23:48:00.012 695 9871 D audio_hw_utils: audio_extn_utils_send_app_type_cfg: usecase->out_snd_device voice-handset
03-04 23:48:00.012 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(16) num devices(0) new_snd_devices(0)
03-04 23:48:00.012 695 9871 D audio_hw_utils: audio_extn_btsco_get_sample_rate:Not a BT SCO device, need not update sampling rate
03-04 23:48:00.012 695 9871 I audio_hw_utils: send_app_type_cfg_for_device PLAYBACK app_type 69937, acdb_dev_id 7, sample_rate 48000, snd_device_be_idx 2
03-04 23:48:00.013 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(16) num devices(1) new_snd_devices(0)
03-04 23:48:00.013 695 9871 D audio_hw_utils: audio_extn_btsco_get_sample_rate:Not a BT SCO device, need not update sampling rate
03-04 23:48:00.013 695 9871 D ACDB-LOADER: ACDB -> send_audio_cal, acdb_id = 7, path = 0, app id = 0x11131, sample rate = 48000, afe_sample_rate = 48000
03-04 23:48:00.013 695 9871 D ACDB-LOADER: ACDB -> send_asm_topology
03-04 23:48:00.013 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TOPOLOGY_ID
03-04 23:48:00.013 695 9871 D ACDB-LOADER: ACDB -> send_adm_topology
03-04 23:48:00.013 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TOPOLOGY_ID
03-04 23:48:00.013 695 9871 D ACDB-LOADER: ACDB -> send_audtable
03-04 23:48:00.013 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE_SIZE
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_COMMON_TABLE
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_AUDPROC_CAL cal_type[11] acdb_id[7] app_type[69937]
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> send_audvoltable
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE_SIZE
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_GAIN_DEP_STEP_TABLE, vol index 0
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_VOL_CAL cal type = 12
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TABLE_SIZE
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> send_audstrmtable
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AUDPROC_STREAM_TABLE_V2
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> audstrm_cal->cal_type.cal_data.cal_size = 16
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> send_afe_topology
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_TOPOLOGY_ID
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> GET_AFE_TOPOLOGY_ID for adcd_id 7, Topology Id 112fc
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> send_afe_cal
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE
03-04 23:48:00.014 695 9871 D : Failed to fetch the lookup information of the device 00000007
03-04 23:48:00.014 695 9871 D ACDB-LOADER: Error: ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE Returned = -19
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE
03-04 23:48:00.014 695 9871 D : Failed to fetch the lookup information of the device 00000007
03-04 23:48:00.014 695 9871 D ACDB-LOADER: Error: ACDB AFE returned = -19
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_AFE_CAL cal_type[16] acdb_id[7]
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> send_hw_delay : acdb_id = 7 path = 0
03-04 23:48:00.014 695 9871 D ACDB-LOADER: ACDB -> ACDB_AVSYNC_INFO: ACDB_CMD_GET_DEVICE_PROPERTY
03-04 23:48:00.014 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(16) num devices(0) new_snd_devices(0)
03-04 23:48:00.014 695 9871 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 16
03-04 23:48:00.014 695 9871 D audio_hw_primary: enable_audio_route: apply mixer and update path: low-latency-playback voice-handset
03-04 23:48:00.014 695 9871 D audio_route: Apply path: low-latency-playback voice-handset
03-04 23:48:00.015 932 932 I Codec2Client: Client to Codec2 service "software" created
03-04 23:48:00.016 9655 9721 W MediaPlayer: Use of stream types is deprecated for operations other than volume control
03-04 23:48:00.016 9655 9721 W MediaPlayer: See the documentation of setAudioStreamType() for what to use instead with android.media.AudioAttributes to qualify your playback use case
03-04 23:48:00.022 932 9876 D GenericSource: FileSource remote
03-04 23:48:00.041 932 9874 I GenericSource: start
03-04 23:48:00.050 932 9880 D CCodec : allocate(c2.android.aac.decoder)
03-04 23:48:00.053 932 9880 I CCodec : Created component [c2.android.aac.decoder]
03-04 23:48:00.054 932 9880 D CCodecConfig: read media type: audio/mp4a-latm
03-04 23:48:00.058 932 9880 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.max-count.values
03-04 23:48:00.058 932 9880 D ReflectedParamUpdater: extent() != 1 for single value type: output.subscribed-indices.values
03-04 23:48:00.059 932 9880 D ReflectedParamUpdater: extent() != 1 for single value type: input.buffers.allocator-ids.values
03-04 23:48:00.059 932 9880 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.allocator-ids.values
03-04 23:48:00.059 932 9880 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.allocator-ids.values
03-04 23:48:00.059 932 9880 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
03-04 23:48:00.060 932 9880 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.pool-ids.values
03-04 23:48:00.064 932 9880 I CCodecConfig: query failed after returning 16 values (BAD_INDEX)
03-04 23:48:00.065 932 9880 D CCodecConfig: c2 config diff is Dict {
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 coded.aac-packaging.value = 0
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 coded.bitrate.value = 64000
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 coded.pl.level = 0
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 coded.pl.profile = 8192
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::float coding.drc.attenuation-factor.value = 1
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::float coding.drc.boost-factor.value = 1
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::i32 coding.drc.compression-mode.value = 3
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::i32 coding.drc.effect-type.value = 3
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::float coding.drc.encoded-level.value = 0.25
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::float coding.drc.reference-level.value = -16
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 input.buffers.max-size.value = 8192
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 input.delay.value = 0
03-04 23:48:00.065 932 9880 D CCodecConfig: string input.media-type.value = "audio/mp4a-latm"
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 output.delay.value = 2
03-04 23:48:00.065 932 9880 D CCodecConfig: string output.media-type.value = "audio/raw"
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 raw.channel-count.value = 1
03-04 23:48:00.065 932 9880 D CCodecConfig: c2::u32 raw.sample-rate.value = 44100
03-04 23:48:00.065 932 9880 D CCodecConfig: }
03-04 23:48:00.067 932 9880 D CCodecConfig: no c2 equivalents for durationUs
03-04 23:48:00.067 932 9880 D CCodecConfig: no c2 equivalents for language
03-04 23:48:00.067 932 9880 D CCodecConfig: no c2 equivalents for encoder-delay
03-04 23:48:00.067 932 9880 D CCodecConfig: no c2 equivalents for encoder-padding
03-04 23:48:00.067 932 9880 D CCodecConfig: no c2 equivalents for aac-profile
03-04 23:48:00.068 932 9880 D CCodecConfig: config failed => CORRUPTED
03-04 23:48:00.069 932 9880 D CCodecConfig: c2 config diff is c2::u32 raw.channel-count.value = 2
03-04 23:48:00.070 932 9880 W Codec2Client: query -- param skipped: index = 1107298332.
03-04 23:48:00.070 932 9880 D CCodec : client requested max input size 696, which is smaller than what component recommended (8192); overriding with component recommendation.
03-04 23:48:00.070 932 9880 W CCodec : This behavior is subject to change. It is recommended that app developers double check whether the requested max input size is in reasonable range.
03-04 23:48:00.070 932 9880 D CCodec : setup formats input: AMessage(what = 0x00000000) = {
03-04 23:48:00.070 932 9880 D CCodec : int32_t channel-count = 2
03-04 23:48:00.070 932 9880 D CCodec : int32_t level = 0
03-04 23:48:00.070 932 9880 D CCodec : int32_t max-input-size = 8192
03-04 23:48:00.070 932 9880 D CCodec : string mime = "audio/mp4a-latm"
03-04 23:48:00.070 932 9880 D CCodec : int32_t profile = 2
03-04 23:48:00.070 932 9880 D CCodec : int32_t sample-rate = 44100
03-04 23:48:00.070 932 9880 D CCodec : } and output: AMessage(what = 0x00000000) = {
03-04 23:48:00.070 932 9880 D CCodec : int32_t channel-count = 2
03-04 23:48:00.070 932 9880 D CCodec : string mime = "audio/raw"
03-04 23:48:00.070 932 9880 D CCodec : int32_t sample-rate = 44100
03-04 23:48:00.070 932 9880 D CCodec : int32_t encoder-delay = 2112
03-04 23:48:00.070 932 9880 D CCodec : int32_t encoder-padding = 65
03-04 23:48:00.070 932 9880 D CCodec : }
03-04 23:48:00.071 932 9880 I MediaCodec: MediaCodec will operate in async mode
03-04 23:48:00.071 695 8642 D msm8916_platform: platform_split_snd_device: snd_device(16) num devices(0) new_snd_devices(0)
03-04 23:48:00.072 695 8642 I msm8916_platform: platform_get_custom_mtmx_params: no matching param with id 0 ip_ch 2 op_ch 1 uc_id 1 snd_dev 16
03-04 23:48:00.073 695 9871 D hardware_info: hw_info_append_hw_type : device_name = voice-handset
03-04 23:48:00.073 932 9880 W Codec2Client: query -- param skipped: index = 1342179345.
03-04 23:48:00.073 932 9880 W Codec2Client: query -- param skipped: index = 2415921170.
03-04 23:48:00.073 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(16) num devices(0) new_snd_devices(0)
03-04 23:48:00.073 932 9880 W Codec2Client: query -- param skipped: index = 1610614798.
03-04 23:48:00.073 695 9871 I msm8916_platform: platform_check_and_set_capture_codec_backend_cfg:txbecf: afe: bitwidth 16, samplerate 48000, channel 1 format 1, backend_idx 7 usecase = 38 device (voice-dmic-ef)
03-04 23:48:00.073 695 9871 I msm8916_platform: platform_check_capture_codec_backend_cfg:txbecf: afe: Codec selected backend: 7 current bit width: 16 and sample rate: 48000, channels 1 format 1
03-04 23:48:00.073 695 9871 W msm8916_platform: platform_check_capture_codec_backend_cfg:txbecf: afe:Use default bw and sr for voice/voip calls
03-04 23:48:00.073 695 9871 I msm8916_platform: platform_check_capture_codec_backend_cfg:txbecf: afe: Codec selected backend: 7 updated bit width: 16 and sample rate: 48000
03-04 23:48:00.073 695 9871 D audio_hw_primary: check_usecases_capture_codec_backend:becf: force routing 0
03-04 23:48:00.073 695 9871 D hardware_info: hw_info_append_hw_type : device_name = voice-dmic-ef
03-04 23:48:00.073 695 9871 D msm8916_platform: platform_split_snd_device: snd_device(95) num devices(0) new_snd_devices(0)
03-04 23:48:00.073 695 9871 D audio_hw_primary: enable_snd_device: snd_device(95: voice-dmic-ef)
03-04 23:48:00.073 695 9871 I soundtrigger: audio_extn_sound_trigger_update_device_status: device 0x5f of type 1 for Event 1, with Raise=1
03-04 23:48:00.074 695 9871 I sound_trigger_platform: platform_stdev_check_and_update_concurrency: Received DEVICE event, event type 1
03-04 23:48:00.074 695 9871 D sound_trigger_platform: platform_stdev_check_and_update_concurrency: dedicated path 0, reset backend 1, tx 1, rx 0,concurrency session not allowed
03-04 23:48:00.074 695 9871 D audio_route: Apply path: voice-dmic-ef
03-04 23:48:00.076 932 9880 D BufferPoolAccessor: bufferpool2 0xeaae8810 : 12(98304 size) total buffers - 8(65536 size) used buffers - 80/92 (recycle/alloc) - 12/92 (fetch/transfer)
03-04 23:48:00.076 932 9880 D CCodecBufferChannel: [c2.android.aac.decoder#341] Created input block pool with allocatorID 16 => poolID 21 - OK (0)
03-04 23:48:00.078 972 2364 D BufferPoolAccessor: bufferpool2 0x334c791030 : 6(24576 size) total buffers - 0(0 size) used buffers - 82/88 (recycle/alloc) - 6/88 (fetch/transfer)
03-04 23:48:00.079 932 9880 I CCodecBufferChannel: [c2.android.aac.decoder#341] Created output block pool with allocatorID 16 => poolID 33 - OK
03-04 23:48:00.079 932 9880 D CCodecBufferChannel: [c2.android.aac.decoder#341] Configured output block pool ids 33 => OK
03-04 23:48:00.085 972 9881 D SimpleC2Component: Using output block pool with poolID 33 => got 33 - 0
03-04 23:48:00.091 972 9881 I C2SoftAacDec: Reconfiguring decoder: 0->44100 Hz, 0->2 channels
03-04 23:48:00.109 695 9871 D ACDB-LOADER: ACDB -> send_voice_cal, acdb_rx = 7, acdb_tx = 41, feature_set = 0
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> send_voice_rx_topology
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOCPROC_COMMON_TOPOLOGY_ID
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_TARGET_SPECIFIC_DEVICE_INFO
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CHANNEL_MAPPING_CONFIG: GET_DEVICE_PROPERTY
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> send_voice_tx_topology
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOCPROC_COMMON_TOPOLOGY_ID
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_TARGET_SPECIFIC_DEVICE_INFO
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CHANNEL_MAPPING_CONFIG: GET_DEVICE_PROPERTY
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_SIDETONE_IIR_CAL
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_DATA
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_SIDETONE_CAL
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> send_voice_columns, rxacdb_id 7, txacdb_id 41, table 5
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_COLUMNS_INFO_V2
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_PROC_STATIC_TABLE_SIZE
03-04 23:48:00.110 695 9871 D : ACDBFILE_MGR: Property for the pid 0001327F not found
03-04 23:48:00.110 695 9871 D : ACDB_COMMAND: Failed to fetch the property info for pid 0001327F
03-04 23:48:00.110 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_PROC_STATIC_TABLE
03-04 23:48:00.110 695 9871 D : ACDBFILE_MGR: Property for the pid 0001327F not found
03-04 23:48:00.110 695 9871 D : ACDB_COMMAND: Failed to fetch the property info for pid 0001327F
03-04 23:48:00.111 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_VOCPROC_CAL
03-04 23:48:00.111 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_PROC_DEVICE_CFG
03-04 23:48:00.111 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_VOCPROC_DEV_CFG_CAL
03-04 23:48:00.112 695 9871 D ACDB-LOADER: ACDB -> send_voice_columns, rxacdb_id 7, txacdb_id 41, table 4
03-04 23:48:00.112 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_COLUMNS_INFO_V2
03-04 23:48:00.112 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_PROC_DYNAMIC_TABLE_SIZE
03-04 23:48:00.112 695 9871 D : ACDBFILE_MGR: Property for the pid 0001327F not found
03-04 23:48:00.112 695 9871 D : ACDB_COMMAND: Failed to fetch the property info for pid 0001327F
03-04 23:48:00.113 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_PROC_DYNAMIC_TABLE
03-04 23:48:00.113 695 9871 D : ACDBFILE_MGR: Property for the pid 0001327F not found
03-04 23:48:00.113 695 9871 D : ACDB_COMMAND: Failed to fetch the property info for pid 0001327F
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_VOCPROC_VOL_CAL
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> send_voice_columns, rxacdb_id 7, txacdb_id 41, table 6
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_COLUMNS_INFO_V2
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_STREAM_STATIC_TABLE_SIZE
03-04 23:48:00.116 695 9871 D : ACDBFILE_MGR: Property for the pid 0001327F not found
03-04 23:48:00.116 695 9871 D : ACDB_COMMAND: Failed to fetch the property info for pid 0001327F
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_VOC_STREAM_STATIC_TABLE
03-04 23:48:00.116 695 9871 D : ACDBFILE_MGR: Property for the pid 0001327F not found
03-04 23:48:00.116 695 9871 D : ACDB_COMMAND: Failed to fetch the property info for pid 0001327F
03-04 23:48:00.116 695 733 D audio_hw_primary: adev_get_parameters:vr_audio_mode_on
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_VOCPROC_STREAM_CAL
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> send_afe_topology
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_TOPOLOGY_ID
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> GET_AFE_TOPOLOGY_ID for adcd_id 41, Topology Id 112fb
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> send_afe_cal
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE
03-04 23:48:00.116 695 9871 D : Failed to fetch the lookup information of the device 00000029
03-04 23:48:00.116 695 9871 D ACDB-LOADER: Error: ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE Returned = -19
03-04 23:48:00.116 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE
03-04 23:48:00.116 695 9871 D : Failed to fetch the lookup information of the device 00000029
03-04 23:48:00.117 695 9871 D ACDB-LOADER: Error: ACDB AFE returned = -19
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_AFE_CAL cal_type[17] acdb_id[41]
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> send_afe_topology
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_TOPOLOGY_ID
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> GET_AFE_TOPOLOGY_ID for adcd_id 7, Topology Id 112fc
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> send_afe_cal
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE
03-04 23:48:00.117 695 9871 D : Failed to fetch the lookup information of the device 00000007
03-04 23:48:00.117 695 9871 D ACDB-LOADER: Error: ACDB_CMD_GET_AFE_COMMON_TABLE_SIZE Returned = -19
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> ACDB_CMD_GET_AFE_COMMON_TABLE
03-04 23:48:00.117 695 9871 D : Failed to fetch the lookup information of the device 00000007
03-04 23:48:00.117 695 9871 D ACDB-LOADER: Error: ACDB AFE returned = -19
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> AUDIO_SET_AFE_CAL cal_type[16] acdb_id[7]
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> send_hw_delay : acdb_id = 41 path = 1
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> ACDB_AVSYNC_INFO: ACDB_CMD_GET_DEVICE_PROPERTY
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> send_hw_delay : acdb_id = 7 path = 0
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> ACDB_AVSYNC_INFO: ACDB_CMD_GET_DEVICE_PROPERTY
03-04 23:48:00.117 695 9871 D ACDB-LOADER: ACDB -> Sent VocProc Cal!
03-04 23:48:00.117 695 9871 E audio_hw_utils: audio_extn_utils_update_stream_app_type_cfg_for_usecase: app type cfg not supported for usecase type (3)
03-04 23:48:00.117 695 9871 D soundtrigger: audio_extn_sound_trigger_update_stream_status: uc_info->id 38 of type 3 for Event 3, with Raise=1
03-04 23:48:00.117 695 9871 I audio_hw_utils: audio_extn_utils_send_app_type_cfg: not a playback/capture path, no need to cfg app type
03-04 23:48:00.117 695 9871 D audio_hw_primary: enable_audio_route: apply mixer and update path: compress-voip-call voice-handset
03-04 23:48:00.117 695 9871 D audio_route: Apply path: compress-voip-call voice-handset
03-04 23:48:00.125 695 9871 D audio_hw_primary: select_devices: done
03-04 23:48:00.125 695 9871 D compress_voip: voip_start_call: Opening PCM capture device card_id(0) device_id(3)
03-04 23:48:00.126 695 9871 D compress_voip: voip_start_call: Opening PCM playback device card_id(0) device_id(3)
03-04 23:48:00.235 695 9871 D voice : voice_set_sidetone: enable, out_snd_device: 16
03-04 23:48:00.235 695 9871 D audio_route: Apply path: sidetone-handset
03-04 23:48:00.322 755 1413 D AudioFlinger: mixer(0x7ce2d42f40) throttle end: throttle time(16)
03-04 23:48:02.006 932 1036 D NuPlayerDriver: stop(0xeaa5c780)
03-04 23:48:02.555 612 9883 E ResolverController: No valid NAT64 prefix (100, <unspecified>/0)
03-04 23:48:05.115 755 1931 I TimeCheck: requesting tombstone for pid: 695
03-04 23:48:05.117 695 695 I libc : Requested dump for tid 695 (audio@2.0-servi)
03-04 23:48:06.122 755 1931 F TimeCheck: TimeCheck timeout for IAudioFlinger command 1
03-04 23:48:06.136 755 1931 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 1931 (TimeCheckThread), pid 755 (audioserver)
03-04 23:48:06.277 9895 9895 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone
03-04 23:48:06.280 1017 1017 I /system/bin/tombstoned: received crash request for pid 1931
03-04 23:48:06.287 9895 9895 I crash_dump64: performing dump of process 755 (target tid = 1931)
03-04 23:48:06.299 9895 9895 F DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
03-04 23:48:06.299 9895 9895 F DEBUG : LineageOS Version: '0.14-q-2021012698290-dev-FP3'
03-04 23:48:06.299 9895 9895 F DEBUG : Build fingerprint: 'Fairphone/FP3/FP3:10/8901.3.A.0054-SS.20201014/10141150:user/release-keys'
03-04 23:48:06.299 9895 9895 F DEBUG : Revision: '0'
03-04 23:48:06.299 9895 9895 F DEBUG : ABI: 'arm64'
03-04 23:48:06.301 9895 9895 F DEBUG : Timestamp: 2021-03-04 23:48:06+0100
03-04 23:48:06.301 9895 9895 F DEBUG : pid: 755, tid: 1931, name: TimeCheckThread >>> /system/bin/audioserver <<<
03-04 23:48:06.301 9895 9895 F DEBUG : uid: 1041
03-04 23:48:06.301 9895 9895 F DEBUG : signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
03-04 23:48:06.301 9895 9895 F DEBUG : Abort message: 'TimeCheck timeout for IAudioFlinger command 1'
03-04 23:48:06.301 9895 9895 F DEBUG : x0 0000000000000000 x1 000000000000078b x2 0000000000000006 x3 0000007c4ed3e660
03-04 23:48:06.301 9895 9895 F DEBUG : x4 0c093730110c1d27 x5 0c093730110c1d27 x6 0c093730110c1d27 x7 271d0c113037090c
03-04 23:48:06.302 9895 9895 F DEBUG : x8 00000000000000f0 x9 3ad27491dc79412e x10 0000000000000001 x11 0000000000000000
03-04 23:48:06.302 9895 9895 F DEBUG : x12 fffffff0ffffffdf x13 0000000000000000 x14 0000000000000000 x15 0c093730110c1d27
03-04 23:48:06.302 9895 9895 F DEBUG : x16 0000007cdf4a28c0 x17 0000007cdf4803b0 x18 0000007c4d89a000 x19 00000000000002f3
03-04 23:48:06.302 9895 9895 F DEBUG : x20 000000000000078b x21 00000000ffffffff x22 0000007c00000000 x23 0000007c5d112134
03-04 23:48:06.302 9895 9895 F DEBUG : x24 0000007c5d112134 x25 0000007c4ed3ed50 x26 0000007c4ed3f020 x27 0000007ce2f89020
03-04 23:48:06.302 9895 9895 F DEBUG : x28 0000000000000000 x29 0000007c4ed3e700
03-04 23:48:06.302 9895 9895 F DEBUG : sp 0000007c4ed3e640 lr 0000007cdf433f48 pc 0000007cdf433f74
03-04 23:48:06.314 9895 9895 F DEBUG :
03-04 23:48:06.314 9895 9895 F DEBUG : backtrace:
03-04 23:48:06.314 9895 9895 F DEBUG : #00 pc 0000000000081f74 /apex/com.android.runtime/lib64/bionic/libc.so (abort+160) (BuildId: bf14cf7a62d1f91755beddd4a937354d)
03-04 23:48:06.314 9895 9895 F DEBUG : #01 pc 00000000000089f8 /system/lib64/liblog.so (__android_log_assert+324) (BuildId: fa7cbba17f5086fc8671eb6757477dd0)
03-04 23:48:06.314 9895 9895 F DEBUG : #02 pc 0000000000010540 /system/lib64/libmediautils.so (android::TimeCheck::TimeCheckThread::threadLoop()+532) (BuildId: 8bc3a9ee69d10e88e05d37c03fe4d20c)
03-04 23:48:06.315 9895 9895 F DEBUG : #03 pc 0000000000013688 /system/lib64/libutils.so (android::Thread::_threadLoop(void*)+316) (BuildId: 59cf3fe4181b87b327cc75164d8ebaa8)
03-04 23:48:06.315 9895 9895 F DEBUG : #04 pc 00000000000e2390 /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+36) (BuildId: bf14cf7a62d1f91755beddd4a937354d)
03-04 23:48:06.315 9895 9895 F DEBUG : #05 pc 0000000000083ab0 /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: bf14cf7a62d1f91755beddd4a937354d)
Critical logcat section tested with Conversations. (for Conversations it's a crash of "IAudioPolicyService")
03-04 19:49:54.300 763 1928 F TimeCheck: TimeCheck timeout for IAudioPolicyService command 6
03-04 19:49:54.310 763 1928 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 1928 (TimeCheckThread), pid 763 (audioserver)
03-04 19:49:54.395 16416 16416 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone
03-04 19:49:54.403 1086 1086 I /system/bin/tombstoned: received crash request for pid 1928
03-04 19:49:54.407 16416 16416 I crash_dump64: performing dump of process 763 (target tid = 1928)
03-04 19:49:54.414 16416 16416 F DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
03-04 19:49:54.414 16416 16416 F DEBUG : LineageOS Version: '0.14-q-2021012698290-dev-FP3'
03-04 19:49:54.414 16416 16416 F DEBUG : Build fingerprint: 'Fairphone/FP3/FP3:10/8901.3.A.0054-SS.20201014/10141150:user/release-keys'
03-04 19:49:54.414 16416 16416 F DEBUG : Revision: '0'
03-04 19:49:54.414 16416 16416 F DEBUG : ABI: 'arm64'
03-04 19:49:54.415 16416 16416 F DEBUG : Timestamp: 2021-03-04 19:49:54+0100
03-04 19:49:54.415 16416 16416 F DEBUG : pid: 763, tid: 1928, name: TimeCheckThread >>> /system/bin/audioserver <<<
03-04 19:49:54.415 16416 16416 F DEBUG : uid: 1041
03-04 19:49:54.415 16416 16416 F DEBUG : signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
03-04 19:49:54.415 16416 16416 F DEBUG : Abort message: 'TimeCheck timeout for IAudioPolicyService command 6'
03-04 19:49:54.416 16416 16416 F DEBUG : x0 0000000000000000 x1 0000000000000788 x2 0000000000000006 x3 0000007429aca660
03-04 19:49:54.416 16416 16416 F DEBUG : x4 0c093730110c1d27 x5 0c093730110c1d27 x6 0c093730110c1d27 x7 271d0c113037090c
03-04 19:49:54.416 16416 16416 F DEBUG : x8 00000000000000f0 x9 6e88ba53012d2b7f x10 0000000000000001 x11 0000000000000000
03-04 19:49:54.416 16416 16416 F DEBUG : x12 fffffff0ffffffdf x13 0000000000000000 x14 0000000000000000 x15 0c093730110c1d27
03-04 19:49:54.416 16416 16416 F DEBUG : x16 00000074bb6c28c0 x17 00000074bb6a03b0 x18 00000074262e0000 x19 00000000000002fb
03-04 19:49:54.416 16416 16416 F DEBUG : x20 0000000000000788 x21 00000000ffffffff x22 0000007400000000 x23 00000074bcb9f85c
03-04 19:49:54.416 16416 16416 F DEBUG : x24 00000074bcb9f85c x25 0000007429acad50 x26 0000007429acb020 x27 00000074bce11020
03-04 19:49:54.416 16416 16416 F DEBUG : x28 0000000000000000 x29 0000007429aca700
03-04 19:49:54.416 16416 16416 F DEBUG : sp 0000007429aca640 lr 00000074bb653f48 pc 00000074bb653f74
03-04 19:49:54.431 16416 16416 F DEBUG :
03-04 19:49:54.431 16416 16416 F DEBUG : backtrace:
03-04 19:49:54.431 16416 16416 F DEBUG : #00 pc 0000000000081f74 /apex/com.android.runtime/lib64/bionic/libc.so (abort+160) (BuildId: bf14cf7a62d1f91755beddd4a937354d)
03-04 19:49:54.431 16416 16416 F DEBUG : #01 pc 00000000000089f8 /system/lib64/liblog.so (__android_log_assert+324) (BuildId: fa7cbba17f5086fc8671eb6757477dd0)
03-04 19:49:54.431 16416 16416 F DEBUG : #02 pc 0000000000010540 /system/lib64/libmediautils.so (android::TimeCheck::TimeCheckThread::threadLoop()+532) (BuildId: 8bc3a9ee69d10e88e05d37c03fe4d20c)
03-04 19:49:54.431 16416 16416 F DEBUG : #03 pc 0000000000013688 /system/lib64/libutils.so (android::Thread::_threadLoop(void*)+316) (BuildId: 59cf3fe4181b87b327cc75164d8ebaa8)
03-04 19:49:54.431 16416 16416 F DEBUG : #04 pc 00000000000e2390 /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+36) (BuildId: bf14cf7a62d1f91755beddd4a937354d)
03-04 19:49:54.431 16416 16416 F DEBUG : #05 pc 0000000000083ab0 /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: bf14cf7a62d1f91755beddd4a937354d)