Not working on Android 12, LOS+microG

Lavmint commented 2 years ago

What happened

Nothing at all (no recordings, no empty files, no errors)

What did I do?

enabled call recording
selected output directory
disabled buttery optimization
call on 123456 number to get input

Other

Tested with both enabled and disabled VOCREC* mixers in /vendor/etc
Axet's call recorder works weirdly, maybe because it's 2 mixers in /vendor/etc/mixer_paths_tasha.xml. If to play with switches, it may start working but not for long. Also it seems that skip silence somehow affects recording too
Mixer info is at the end of the issue
ROM: https://download.lineage.microg.org/cheeseburger/

DeviceInfo

build.board: msm8998
build.bootloader: unknown
build.brand: OnePlus
build.cpu_abi: arm64-v8a
build.cpu_abi2: 
build.device: OnePlus5
build.display: lineage_cheeseburger-userdebug 12 SP2A.220505.002 eng.root.20220608.224223 dev-keys
build.fingerprint: OnePlus/OnePlus5/OnePlus5:10/QKQ1.191014.012/2010292059:user/release-keys
build.hardware: qcom
build.host: a6c8e04ec309
build.id: SP2A.220505.002
build.manufacturer: OnePlus
build.model: ONEPLUS A5000
build.product: OnePlus5
build.radio: unknown
build.serial: unknown
build.tags: dev-keys
build.time: 1654728040000
build.type: userdebug
build.user: root
version.codename: REL
version.incremental: eng.root.20220608.224223
version.release: 12
version.sdk_int: 32

Logcat

06-16 20:10:56.584 I/Telecom (1498): InCallServiceBindingConnection: Attempting to bind to InCall [ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService} supportsExternal? false supportsSelfMg?false], with Intent { act=android.telecom.InCallService cmp=com.chiller3.bcr/.RecorderInCallService (has extras) }: TSI.pC->CM.fOCP->CM.sOCPA->CM.dSMCP->CM.dSPA->CM.pASP@BQc
06-16 20:10:56.600 I/Telecom (1498): InCallController: onConnected to ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}: ICSBC.oSC(ccb)@BQg
06-16 20:10:56.601 I/Telecom (1498): InCallController: Adding 1 calls to InCallService after onConnected: ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}, including external calls: ICSBC.oSC(ccb)@BQg
06-16 20:10:56.663 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: NOCBIR.oR@BRE
06-16 20:10:56.736 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.737 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.740 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.741 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.744 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.744 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.745 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.751 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: (...->CS.crCo->H.CS.crCo->H.CS.crCo.pICR)->CSW.hCCC(cap/cast)@E-E-BRI
06-16 20:10:56.755 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sSH(cap)@BRk
06-16 20:10:56.756 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@BRo
06-16 20:10:56.758 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@BRs
06-16 20:10:56.759 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sSH(cap)@BRw
06-16 20:10:56.761 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@BR0
06-16 20:10:56.763 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@BR4
06-16 20:10:56.867 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sSH(cap)@BVo
06-16 20:10:56.869 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sCDN(cap)@BVw
06-16 20:10:56.870 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@BV4
06-16 20:10:56.871 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@BV8
06-16 20:10:59.656 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sCC(cap)@Beg
06-16 20:10:59.664 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sSH(cap)@Bek
06-16 20:10:59.670 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@Bes
06-16 20:10:59.676 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.rE(cap)@Be0
06-16 20:11:06.623 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sSH(cap)@BhQ
06-16 20:11:06.625 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sDc(cap)@BhU
06-16 20:11:06.642 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sCC(cap)@Bhg
06-16 20:11:06.644 I/Telecom (1498): InCallController: Components updated: [ComponentInfo{com.android.dialer/com.android.incallui.InCallServiceImpl}, ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}]: CSW.sCC(cap)@Bhs
06-16 20:11:08.650 I/Telecom (1498): InCallController: ICSBC#disconnect: unbinding after 12066 ms;[ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService} supportsExternal? false supportsSelfMg?false]. isCrashed: false: CSW.rC->CM.pR->ICC.oCR(cap)@Bhw
06-16 20:11:08.660 I/Telecom (1498): InCallController: onDisconnected from ComponentInfo{com.chiller3.bcr/com.chiller3.bcr.RecorderInCallService}: CSW.rC->CM.pR->ICC.oCR(cap)@Bhw

Mixer

    <!-- Incall Recording -->
    <ctl name="MultiMedia9 Mixer VOC_REC_UL" value="0" />
    <ctl name="MultiMedia9 Mixer VOC_REC_DL" value="0" />
    <ctl name="MultiMedia8 Mixer VOC_REC_UL" value="0" />
    <ctl name="MultiMedia8 Mixer VOC_REC_DL" value="0" />
    <!-- Incall Recording End -->
--
    <path name="incall-rec-uplink">
        <ctl name="MultiMedia9 Mixer VOC_REC_UL" value="0" />
    </path>
--
    <path name="incall-rec-uplink-compress">
        <ctl name="MultiMedia8 Mixer VOC_REC_UL" value="0" />
    </path>
--
    <path name="incall-rec-downlink">
        <ctl name="MultiMedia9 Mixer VOC_REC_DL" value="0" />
    </path>
--
    <path name="incall-rec-downlink-compress">
        <ctl name="MultiMedia8 Mixer VOC_REC_DL" value="0" />
    </path>

Lavmint commented 2 years ago

logs-2022-06-16-20-11-55.zip

chenxiaolong commented 2 years ago

Could you grab the logcat after attempting to make a call? Given that you mentioned this:

Nothing at all (no recordings, no empty files, no errors)

I don't think it's worth looking into the mixer settings just yet. It's likely failing to detect that a call is occurring at all if no output file was created.

When a call comes in, I'd expect it to log the onCallAdded event from RecorderInCallService about the call being in the CONNECTING or RINGING state. For example:

06-10 13:06:18.698 31723 31723 D RecorderInCallService: onCallAdded: Call [id: TC@1, state: CONNECTING, details: [id: TC@1, state: CONNECTING, pa: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, 1, UserHandle{0}, hdl: tel:***********, hdlPres: 1, videoState: Audio Only, caps: [Capabilities: CAPABILITY_SUPPORT_HOLD CAPABILITY_MUTE CAPABILITY_CANNOT_DOWNGRADE_VIDEO_TO_AUDIO], props: [Properties:]]]

If that's not happening, then Android might not be notifying BCR of the call state. This log message should be printed even if call recording is disabled.

I unfortunately can't LineageOS myself. My only device compatible with LineageOS has no VoLTE support, so I can't make calls.

Lavmint commented 2 years ago

@chenxiaolong without filtering logcat is just a mess, here is the full log after attempting to call to 123456 logs-2022-06-16-22-21-20.zip

chenxiaolong commented 2 years ago

Hmm, this part is weird:

logcat.txt:06-16 22:20:03.277 D/RecorderInCallService(8012): onDetailsChanged: Call [id: TC@1, state: DIALING, details: [id: TC@1, state: DIALING, pa: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0}, hdl: tel:****56, hdlPres: 1, videoState: Audio Only, caps: [Capabilities: CAPABILITY_SUPPORT_HOLD CAPABILITY_MUTE CAPABILITY_CANNOT_DOWNGRADE_VIDEO_TO_AUDIO], props: [Properties:]]], [id: TC@1, state: DIALING, pa: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0}, hdl: tel:****56, hdlPres: 1, videoState: Audio Only, caps: [Capabilities: CAPABILITY_SUPPORT_HOLD CAPABILITY_MUTE CAPABILITY_CANNOT_DOWNGRADE_VIDEO_TO_AUDIO], props: [Properties:]]

<...>

logcat.txt:06-16 22:20:08.211 D/RecorderInCallService(8012): onStateChanged: Call [id: TC@1, state: DISCONNECTING, details: [id: TC@1, state: DISCONNECTING, pa: ComponentInfo{com.android.phone/com.android.services.telephony.TelephonyConnectionService}, ***, UserHandle{0}, hdl: tel:****56, hdlPres: 1, videoState: Audio Only, caps: [Capabilities: CAPABILITY_SUPPORT_HOLD CAPABILITY_MUTE CAPABILITY_CANNOT_DOWNGRADE_VIDEO_TO_AUDIO], props: [Properties:]]], 10

It's going from the DIALING state straight to DISCONNECTING. I'm not sure what would cause that. It's like the call was ringing, but was hung up before the call was answered. BCR does not record until the call goes into the ACTIVE state.

Lavmint commented 2 years ago

Well,

calling to 123456 results in "This number does not exists" with prerecorded voice message
I'm not listening it to the end and hanging over before it ends telling this message
Axet's call recorder can record my "blah-blah-blah" conversation with this voice message

I've also tried calling real person with BCR today, also with no luck. I will try to log call to real person tomorrow and will attach it too, maybe it would have different states flow

Lavmint commented 2 years ago

@chenxiaolong a tried a few cases

Mixer enabled, recording into folder Recordings - file exists, recorded with sound
Mixer disabled, recording into folder Recordings - file exists, recorded without sound (silence). BCR is not enabling/relying on mixer like Axet's recorder?
Mixer enabled, recording into folder Call Recordings - file exists, recorded with sound

Calling to 123456 is not a proper way to test BCR, this only works with axet since it's expecting other state - ok

I don't get it why I had 1 call that was not recorded without any files and why it's working know. In case 3 I've tested output directory with space between words and it's not the case

Meh, for now the only question I got is about mixer. Shouldn't BCR provide ability to enable it? Since I didn't catch original issue's behavior I'm not attaching any logs

Lavmint commented 2 years ago

Conclusion and user-exp:

to enable mixer you can use axet's app or do it by hand via adb shell in /vendor/etc/mixers* (don't forget to reboot)
could not reproduce original issue

Issue closed for now as of all working and recorded now

chenxiaolong / BCR