Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Skip to content

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:

 

The problem

  1. Lock the screen on your FP3+. (until now I only reproduced the bug when the screen was locked)
  2. Call from another device.
  3. Pick up the call on the FP3+.
  4. 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:

 

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)
Edited by kolAflash