Figure

HI ALL

当前分析：
根据日志分析，我们发现此时和中控的连接已经断开，
导致了获取焦点失败，然后我们主动停止播放，应用再去调用播放时会返回error，就会出现不支持的信息。

532:05-26 14:33:27.092  1529 11911 I MediaFocusControl: requestAudioFocus() from uid/pid 10087/3531 AA=USAGE_MEDIA/CONTENT_TYPE_MUSIC clientId=android.media.AudioManager@2ba1e02com.android.music.MediaPlaybackService$4@5ef9313 callingPack=com.android.music req=1 flags=0x0 sdk=31
533:05-26 14:33:27.092  1529 11911 D AudioService.PlaybackActivityMonitor: idcm_af:requestAudioFocusToIDCM: event=2(PLAYER_STATE_STARTED)apc =AudioPlaybackConfiguration piid:367 deviceId:0 type:android.media.MediaPlayer u/pid:10087/3531 state:idle attr:AudioAttributes: usage=USAGE_MEDIA content=CONTENT_TYPE_MUSIC flags=0x800 tags= bundle=null sessionId:0 ★★★ 申请焦点
545:05-26 14:33:27.094  1529 11911 D AudioIDCMicroNegotiator: idcm_af:requestIDCMicroAudioFocus,  streamtype = 3
546:05-26 14:33:27.094  1529 11911 D AudioIDCMicroNegotiator: idcm_af:requestIDCMicroAudioFocus: AudioFocus_Media
552:05-26 14:33:27.094  1529 11911 D AudioIDCMicroNegotiator: idcm_common:requestResult method = requestAudioFocus parameters = {"functionInfo":{"IDCM_AudioFocus":"AudioFocus_Media"}}
554:05-26 14:33:27.094  1529 11911 I MicroServiceManager: requestResult(requestAudioFocus) parameters is{"functionInfo":{"IDCM_AudioFocus":"AudioFocus_Media"}}.
559:05-26 14:33:27.094  1529 11911 D AudioIDCMicroNegotiator: idcm_af:updateAudioInfo
560:05-26 14:33:27.094  1529 11911 D AudioIDCMicroNegotiator: idcm_af:obtainFocusState
595:05-26 14:33:27.095  2058  2099 E MicroService: Client is not connected. ★★★ 微服务断联
605:05-26 14:33:27.095  2058  2099 E MicroService: Client is not connected.
943:05-26 14:33:27.150   813  8086 D audio_hw_primary: select_devices for use case (deep-buffer-playback)
958:05-26 14:33:27.151   813  8086 D audio_hw_primary: enable_snd_device: snd_device(2: speaker)
1068:05-26 14:33:27.695  1529 11911 W AudioIDCMicroNegotiator: idcm_warn: timeout for obtainFocusState: RequestInfosToIDCM{mPid=3531, mUid=10087}
1069:05-26 14:33:27.695  1529 11911 D AudioIDCMicroNegotiator: idcm_af:notifyFocusState -> notify
1070:05-26 14:33:27.695  1529 11911 D AudioIDCMicroNegotiator: idcm_af:obtainFocusState, return: 0 mIsTimeout= true time= 601
1071:05-26 14:33:27.695  1529 11911 D AudioService.PlaybackActivityMonitor: idcm_af:requestAudioFocusToIDCM -> stopPlayer: 367  ★★★ 停止播放
1072:05-26 14:33:27.695  1529  1818 D AudioIDCMicroNegotiator: idcm_af:wait messsage done -> onAudioFocusRemoteChanged
1073:05-26 14:33:27.695  1529  1818 D AudioService.PlaybackActivityMonitor: idcm_af:onAudioFocusRemoteChanged: 0 info= RequestInfosToIDCM{mPid=3531, mUid=10087}
1074:05-26 14:33:27.695  1529  1818 D AS.AudioService: idcm_af:onAudioFocusIDCMicroChanged: 0 info: RequestInfosToIDCM{mPid=3531, mUid=10087}
1075:05-26 14:33:27.695  1529  1818 D MediaFocusControl: audio_idcm: updateCurrentAudioFocus: uid= 10087 fr = 10087 focusChange= -1
1076:05-26 14:33:27.695  1529 11911 D AudioService.PlaybackActivityMonitor: idcm_af:stopPlayer apc= AudioPlaybackConfiguration piid:367 deviceId:0 type:android.media.MediaPlayer u/pid:10087/3531 state:idle attr:AudioAttributes: usage=USAGE_MEDIA content=CONTENT_TYPE_MUSIC flags=0x800 tags= bundle=null sessionId:0
1077:05-26 14:33:27.695  1529  1818 D AudioIDCMicroNegotiator: idcm_af:wait messsage
1078:05-26 14:33:27.695  1529 11911 W AudioService.PlaybackActivityMonitor: idcm_warn: ====rejected by IDCM: PLAYER_STATE_STARTED
1088:05-26 14:33:27.699  1529  1566 D AudioService.PlaybackActivityMonitor: idcm_af:requestAudioFocusToIDCM: event=4(PLAYER_STATE_STOPPED)apc =AudioPlaybackConfiguration piid:367 deviceId:3 type:android.media.MediaPlayer u/pid:10087/3531 state:idle attr:AudioAttributes: usage=USAGE_MEDIA content=CONTENT_TYPE_MUSIC flags=0x800 tags= bundle=null sessionId:0
1104:05-26 14:33:27.734  3531  3531 E MediaPlayerNative: pause called in state 64, mPlayer(0xb4000079308e5f90)
1105:05-26 14:33:27.734  3531  3531 E MediaPlayerNative: error (-38, 0) ★★★ 报错

下一步
需要AF查看网络断开的原因。

Hi,王成，我日志中观察，是由于中控副屏通信未建立成功导致的，但日志确中无法认为什么没有建立成功，需要提供开机上电到bug复现时的日志

■ Current conclusion
发现一处异常情况

■ My analysis

在13:50:01设备muc升级成功，正在重启
05-26 13:50:01.227 1513 25320 I ShutdownThread: Waiting for Radio...
05-26 13:50:01.227 1513 25320 I ShutdownThread: Radio shutdown complete.
05-26 13:50:01.228 1513 25302 I ShutdownThread: Shutdown critical subsyslist is :SDX55M :
05-26 13:50:01.228 1513 25302 I ShutdownThread: Waiting for a maximum of 10000ms
05-26 13:50:01.228 1513 25302 I ShutdownThread: Vendor subsystem(s) shutdown successful
05-26 13:50:01.228 1513 25302 I ShutdownThread: Rebooting, reason: mpu/mcu update success

13:50:10.237 网络搭建成功，收到中控启动的握手请求
05-26 13:50:10.237 2265 4219 I MicroService: Receive message: SocketMessageBean{businessData='21930', srcService='IDCM_COM', destService='FSEM_COM', messageType='2', uuid='0', payloadData={
05-26 13:50:10.237 2265 4219 I MicroService: "dstService" : "FSEM_COM",
05-26 13:50:10.237 2265 4219 I MicroService: "messageType" : 2,
05-26 13:50:10.237 2265 4219 I MicroService: "methodName" : "startup",
05-26 13:50:10.237 2265 4219 I MicroService: "parameters" : {
05-26 13:50:10.237 2265 4219 I MicroService: "crash" : "true"
05-26 13:50:10.237 2265 4219 I MicroService: },
05-26 13:50:10.237 2265 4219 I MicroService: "srcService" : "IDCM_COM",
05-26 13:50:10.237 2265 4219 I MicroService: "uuid" : 0
05-26 13:50:10.237 2265 4219 I MicroService: }
05-26 13:50:10.237 2265 4219 I MicroService: }

向中控发送握手验证。
05-26 13:50:10.239 2265 4220 D MicroService: Send message to IDCM:SocketMessageBean{businessData='21930', srcService='FSEM_COM', destService='IDCM_COM', messageType='2', uuid='1685080210237461443', payloadData={"srcService":"FSEM_COM","dstService":"IDCM_COM","messageType":2,"uuid":1685080210237461443,"methodName":"handShake","parameters":{"clientName":"FSEM_COM","clientVersion":"01.10"}}}

后续一直没收到中控握手成功回复，副屏不断尝试继续握手
13:50:17.178发送最后一次握手请求,中控仍然未回复，副屏放弃握手。
05-26 13:50:17.178 2265 2612 D MicroService: send handshake message, currentTryAccount=10
05-26 13:50:17.181 2265 2612 D MicroService: Send message to IDCM:SocketMessageBean{businessData='21930', srcService='FSEM_COM', destService='IDCM_COM', messageType='2', uuid='1684175975707684468', payloadData={"srcService":"FSEM_COM","dstService":"IDCM_COM","messageType":2,"uuid":1684175975707684468,"methodName":"handShake","parameters":{"clientName":"FSEM_COM","clientVersion":"01.10"}}}

■ Next action
副屏重启，与中控请求握手，中控未回复握手成功消息。需要联系中控的中控副屏通信模块研发进行调查中控为什么没有回复握手请求

■ Current conclusion
已经与中控的研发汪洋一起分析了log，疑似网络问题
和祥林一起分析log，发现以太网有问题
■ My analysis
000774_persist_00092_230526_135007.log:05-26 13:50:07.164 2265 2612 E MicroService: DTC_ETH: BaseMicroSocketClient:createClientSocket()
000774_persist_00092_230526_135007.log:05-26 13:50:07.995 0 0 E [ 27.104077] link_delay_work_func: DTC_ETH: SQI=0, link=0
000775_persist_00140_230526_141919.log.ing:05-26 14:19:20.466 2058 2216 E MicroService: DTC_ETH: BaseMicroSocketClient:createClientSocket()
000775_persist_00137_230526_141913.log:05-26 14:19:13.494 0 0 E [ 11.746707] link_delay_work_func: DTC_ETH: SQI=0, link=0
000775_persist_00137_230526_141913.log:05-26 14:19:14.326 2058 2216 E MicroService: DTC_ETH: BaseMicroSocketClient:createClientSocket()
000775_persist_00139_230526_141916.log:05-26 14:19:17.395 2058 2216 E MicroService: DTC_ETH: BaseMicroSocketClient:createClientSocket()
000775_persist_00139_230526_141916.log:05-26 14:19:18.614 0 0 E [ 16.864069] link_delay_work_func: DTC_ETH: SQI=0, link=0

期间有网络断连问题

■ Next action
调查网络问题

Hi,文亮
根据分析，该问题是由网络引起的，请帮忙分析

请见上楼洪普的分析需求。

需和中控分析

请使用最新版本DB，复现故障，抓取日志，保留现场。
fsem上抓取日志：
tcpdump -i eth0 -nnXSs 0 -w /data/fsem.pcap
adb logcat > fsem_logcat.txt
zk上抓取日志：
tcpdump -i eth0 -nnXSs 0 -w /data/zk.pcap
adb logcat > zk_logcat.txt

唐霞测试情况如下：
1）通过adb push 的方式到设备，确实必现。我感觉这个不是问题，音乐文件名称含中文 push到设备后播放提示无法打开，改个名称再push进设备就播放正常了
2）重启后有在“音乐播放器”中看到文件 ，修改名称为英文的音乐文件的播放正常，没有中文修改名称的同一个音乐文件无法播放。
目前结论：应为“中文名称的原因”，请找相关同事解决。

在JIRA上跟踪， 内部关闭此票。

研发（祥林）反馈：客户确认中控收到了副屏焦点请求包，但中控内部处理出现异常，非副屏以太网问题，本BUG关闭