Bug #118085

【IOVDEV-29059】【内部】【VC1】【0080】【台架】【EE环境】【副屏】副屏响应中控语音指令亮屏后，中控语音提示‘副驾屏打开失败’

Added by 物联网测试组_TSCD 王维 about 2 years ago. Updated almost 2 years ago.

Status:CLOSEDStart date:2023-05-18
Priority:NormalDue date:
Assignee:CDTS_Test 吴诗雨% Done:

0%

Category:CD-FW
Target version:-
Need_Info:-- Found Version:副屏：01.00.0095.c103 中控：03.02.0080.C101
Resolution:-- Degrated:--
Severity:Normal Verified Version:
Reproducibility:Every time Fixed Version:
Test Type:ST Root cause:1.语言控制在sdk连接成功的时候不应该再次连接,存在逻辑问题
2.遥控器服务端存在逻辑问题，在连接成功的时候，处理再次连接未回复消息

Description

详情
类型: 故障
状态:开放 (查看工作流)
优先级: C
解决结果:未解决
影响版本:
03.02.0080.C101, 01.00.0095.C103
修复的版本:无
模块:
语音
标签:无
Repetition Rate:
4/10
测试环境:台架手动测试
项目名:
VC1
描述
【环境信息】EE环境
【问题出现时间】：20230518 11:22
【前提条件】：车机上电, 副屏息屏
【操作步骤】
1. 中控端使用语音功能，输入指令“打开副屏”

2.待副屏亮屏后，中控端使用语音功能，输入指令“关闭副屏”

3.待副屏息屏后，中控端使用语音功能，输入指令“打开副屏”

【实际结果】

副屏响应中控指令而亮屏，但中控端语音提示：“副驾屏打开失败”

【期望结果】
副屏响应中控指令而亮屏后，中控的语音提示：副驾屏已打开

【车架号】：HRYTTESTVINMGM400
【备注】：

视频地址：https://ofs.human-horizons.com/#/download/index/05i5tmJKdE0%3D

副屏log地址： https://ofs.human-horizons.com/#/download/index/hJ2JVqmfdHs%3D

中控和副屏的adb log添加在附件中，中控log也可从云端查看

【影响版本】：副屏：01.00.0095.c103 中控：03.02.0080.C101
【硬件版本号】：/
【是否能恢复】：

1122_中控.7z (1.35 MB) 物联网测试组_TSCD 王维, 2023-05-18 20:26

1122_副屏.7z (191 KB) 物联网测试组_TSCD 王维, 2023-05-18 20:26

Related issues

Related to Figure - Bug #118164: 【IOVDEV-29529】【IOV测试】【VC1】【SORP】【语音】【电话】【实车】语音播报：打开副屏，副屏已... CLOSED 2023-05-22

History

#1 Updated by CD FW 曹覃刚 about 2 years ago

  • Category changed from CD-FW to 依赖客户及其供应商解决
  • Status changed from New to NEED_INFO
  • Assignee changed from CD FW 曹覃刚 to 物联网测试组_TSCD 王维

【实际结果】
副屏响应中控指令而亮屏，但中控端语音提示：“副驾屏打开失败”
【期望结果】
副屏响应中控指令而亮屏后，中控的语音提示：副驾屏已打开

问题描述是,副屏是亮屏了的，但是中控的语音提示不正确，这个不应该中控的同事先看看吗？

#2 Updated by CD FW-廖涛 about 2 years ago

■ Current conclusion
从副屏和中控的日志分析，副屏收到中控的亮屏指令后，执行了亮屏，并上报了屏幕状态，从中控日志可以看出，中控已收到对应的上报消息，但是中控在收到屏幕状态消息后，抛出了异常。日志如下：

副屏：
05-18 11:23:10.021 2106 2106 I MicroServiceManager: requestResult(reportScreenDisplay) parameters is{"reportScreenDisplay":1}.
05-18 11:23:10.022 1532 1783 D WifiNetworkFactory: got request NetworkRequest [ REQUEST id=59, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VCN_MANAGED Uid: 10035 RequestorUid: 10035 RequestorPkg: com.microsoft.emmx] ]
05-18 11:23:10.022 1532 1783 D UntrustedWifiNetworkFactory: got request NetworkRequest [ REQUEST id=59, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VCN_MANAGED Uid: 10035 RequestorUid: 10035 RequestorPkg: com.microsoft.emmx] ]
05-18 11:23:10.022 1532 1783 D OemPaidWifiNetworkFactory: got request NetworkRequest [ REQUEST id=59, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VCN_MANAGED Uid: 10035 RequestorUid: 10035 RequestorPkg: com.microsoft.emmx] ]
05-18 11:23:10.023 1532 1790 D ConnectivityService: NetReassign [no changes]
05-18 11:23:10.025 1532 2174 D CompatibilityInfo: mCompatibilityFlags - 4
05-18 11:23:10.025 1532 2174 D CompatibilityInfo: applicationDensity - 240
05-18 11:23:10.025 1532 2174 D CompatibilityInfo: applicationScale - 1.0
05-18 11:23:10.028 2999 2999 D SYS_EVENT: send event 16 notification to client
05-18 11:23:10.031 3163 4398 I downloader:liv: oneway function results for code 1 on binder at 0x73d8dcf120 will be dropped but finished with status UNKNOWN_TRANSACTION
05-18 11:23:10.031 3163 4398 I downloader:liv: oneway function results for code 2 on binder at 0x73d8dcf120 will be dropped but finished with status UNKNOWN_TRANSACTION
05-18 11:23:10.031 1867 1867 D KeyguardViewMediator: handleNotifyScreenTurnedOn
05-18 11:23:10.031 1867 1867 D KeyguardUpdateMonitor: handleTimeUpdate
05-18 11:23:10.032 1867 1867 D KeyguardUpdateMonitor: handleTimeUpdate
05-18 11:23:10.032 2076 6745 D MicroService: Send message to IDCM:SocketMessageBean{businessData='21930', srcService='FSEM_SettingService', destService='IDCM_MultiScreenService', messageType='0', uuid='1684380190021511413', payloadData={"srcService":"FSEM_SettingService","dstService":"IDCM_MultiScreenService","messageType":0,"uuid":1684380190021511413,"methodName":"reportScreenDisplay","parameters":{"reportScreenDisplay":1}}}

中控：
05-18 11:23:10.785 577 610 D HCOMHAL : ---------------------------------
05-18 11:23:10.785 577 610 I HCOMHAL : ReadJson >> size=192:
05-18 11:23:10.785 577 610 I HCOMHAL : {"srcService":"FSEM_SettingService","dstService":"IDCM_MultiScreenService","messageType":0,"uuid":1684380190021511413,"methodName":"reportScreenDisplay","parameters":{"reportScreenDisplay":1}}
05-18 11:23:10.792 898 1783 E IdentifyService: [132] device is not open, id:1
05-18 11:23:10.793 577 614 D HCOMHAL : get msg businessData=0xAA55 src=FSEM_SettingService dst=IDCM_MultiScreenService msgType=0x00 tickCount=1684380190021511413 payloadLength=0x00C0
05-18 11:23:10.793 577 614 D HCOMHAL : on receive callback
05-18 11:23:10.793 577 614 D HCOMHAL : [onEngineReceiveData] src[FSEM_SettingService], dst[IDCM_MultiScreenService], msgType=0, tickCount=1684380190021511413, dsize=192
05-18 11:23:10.793 577 614 D HCOMHAL : [onReceiveData] Enter: src=FSEM_SettingService, dst=IDCM_MultiScreenService msgType=0 tickCount=1684380190021511413 dataLen=192
05-18 11:23:10.793 577 614 D HCOMHAL : [onReceiveData] End
05-18 11:23:10.793 577 607 D HCOMHAL : [onReceiveData]
05-18 11:23:10.793 577 607 D HHTComHalService: dstService:IDCM_MultiScreenService
05-18 11:23:10.794 2644 2818 D MultiScreen_ComhalReceiver: onReceiveData
05-18 11:23:10.794 2644 2818 D MultiScreen_ComhalReceiver: onReceiveData data size:192
05-18 11:23:10.794 2644 2818 D MultiScreen_ComhalReceiver: onReceiveData receiveData = {"srcService":"FSEM_SettingService","dstService":"IDCM_MultiScreenService","messageType":0,"uuid":1684380190021511413,"methodName":"reportScreenDisplay","parameters":{"reportScreenDisplay":1}}
05-18 11:23:10.794 2644 2818 W System.err: org.json.JSONException: No value for ScreenDisplay
05-18 11:23:10.794 2644 2818 W System.err: at org.json.JSONObject.get(JSONObject.java:400)
05-18 11:23:10.794 2644 2818 W System.err: at org.json.JSONObject.getString(JSONObject.java:561)
05-18 11:23:10.794 2644 2818 W System.err: at com.hryt.multiScreenService.comhal.ComhalReceiver$1.onReceiveData(ComhalReceiver.java:68)
05-18 11:23:10.794 2644 2818 W System.err: at vendor.hht.comhal.comhal.V1_0.IComHalListener$Stub.onTransact(IComHalListener.java:567)

■ Next action
测试确认并同步客户。

#3 Updated by CD TEST-方永红 about 2 years ago

  • Status changed from NEED_INFO to ASSIGNED
  • Assignee changed from 物联网测试组_TSCD 王维 to CD FW-廖涛

该问题分为两部分：

（1）遥控器请求打开副屏前 需先请求与副屏连接状态 收到了服务端的错误码 从而设置副屏屏幕状态失败 导致中控语音提示副驾屏打开失败
请协调遥控器SDK同事分析下返回62errorcode的具体原因

05-18 11:23:10.644 5520 6573 E RemoteControlClient_MessageReader: readFromServer: cant get data from service.
05-18 11:23:10.645 5520 6573 I HFSEM_REMOTE_CTRL: RemoteControlRepository-onError code=62;msg=Can not receive data from server.

（2）副屏屏幕此时不该打开 打开原因：遥控器再次请求打开副屏 该逻辑不该存在 同IOVDEV-26824 将在新版本修复

05-18 11:23:10.645 5520 6573 E RemoteControlClient_ConnectionCommand: Now is connected
05-18 11:23:10.657 5520 6668 I HFSEM_REMOTE_CTRL: RemoteControlRepository-screen status:screen_off
05-18 11:23:10.658 5520 6668 I HFSEM_REMOTE_CTRL: RemoteControlOpenApiManager-open co-driver screen

问题2中控已修复
问题1副屏同事处理之后 备注修复SDK版本 副屏版本 并将状态修改为已解决即可
如有中控遥控器相关问题需分析 请备注清楚需要分析的问题再转给我 中控其他问题请转给对应同事

#4 Updated by CD FW 曹覃刚 about 2 years ago

  • Category changed from 依赖客户及其供应商解决 to CD-FW

#5 Updated by CD FW-廖涛 about 2 years ago

  • Category changed from CD-FW to 依赖客户及其供应商解决
  • Status changed from ASSIGNED to NEED_INFO
  • Assignee changed from CD FW-廖涛 to 物联网测试组_TSCD 王维

■ Current conclusion
从副屏日志看，在问题发生时，副屏收到两个遥控器命令，查询屏幕状态和点击 POWER 键，且都成功执行并返回，所以副屏亮屏为正常表现。

日志如下：
05-18 11:23:09.903 2319 2471 I RemoteControlService: RemoteScreenStatusQueryCommand doAction send message: {"source":0,"token":"Ni21TtH51HsNjC4","type":"current_screen_status","value":"screen_off"}
05-18 11:23:09.903 2319 2471 D RemoteControlService: Digest: 263D58CFEA5F4125BF9869A1361154420C86323DBC478A8D8693AB8423256F66
05-18 11:23:09.904 2319 6735 D RemoteControlService: After desEncrypt json is [{"source":0,"token":"Ni21TtH51HsNjC4"}]
05-18 11:23:09.904 2319 6735 D RemoteControlService: buildRemoteCommand:type=23
05-18 11:23:09.904 2319 6735 D RemoteControlService: Request params: BaseRequestCommandBean{source=0, token='Ni21TtH51HsNjC4', type='null', value='null'}
05-18 11:23:09.904 2319 2471 D RemoteControlService: Send data length: 133
05-18 11:23:09.905 2319 2471 D RemoteControlService: Send message finished. direction: 16, messageType: 37, json: {"source":0,"token":"Ni21TtH51HsNjC4","type":"current_screen_status","value":"screen_off"}
05-18 11:23:09.905 2319 2471 D RemoteControlService: RemoteScreenStatusQueryCommand ResponseSpeedTest - use time: 5
05-18 11:23:09.905 2319 2471 D RemoteControlService: handleMessage called
05-18 11:23:09.905 2319 2471 D RemoteControlService: Client-192.168.4.4 handleHeartBeat:154
05-18 11:23:09.905 2319 2471 D RemoteControlService: Is not connect command
05-18 11:23:09.905 2319 2471 D RemoteControlService: haveControl ? clientcom.thundercomm.remotecontrolservice.RemoteControllerClient@8a41378
05-18 11:23:09.905 2319 2471 D RemoteControlService: Client have control
05-18 11:23:09.908 2319 2471 I RemoteControlService: RemoteVolumeQueryCommand doAction send message: {"source":0,"token":"Ni21TtH51HsNjC4","type":"current_volume","value":[{"name":"music","value":19,"value_max":39},{"name":"alarm","value":4,"value_max":7},{"name":"ring","value":3,"value_max":7}]}
05-18 11:23:09.908 2319 2471 D RemoteControlService: Digest: B10F0FBB3949412D30DCD9017718AE155A8735B20580D9481DB18C594CC912E0
05-18 11:23:09.908 2319 2471 D RemoteControlService: Send data length: 245
05-18 11:23:09.909 2319 2471 D RemoteControlService: Send message finished. direction: 16, messageType: 23, json: {"source":0,"token":"Ni21TtH51HsNjC4","type":"current_volume","value":[{"name":"music","value":19,"value_max":39},{"name":"alarm","value":4,"value_max":7},{"name":"ring","value":3,"value_max":7}]}
05-18 11:23:09.909 2319 2471 D RemoteControlService: RemoteVolumeQueryCommand ResponseSpeedTest - use time: 7
05-18 11:23:09.912 2319 2482 D RemoteControlService: getEvent: clientSocket = Socket[address=/192.168.4.4,port=53393,localPort=12600]
05-18 11:23:09.912 2319 2482 D RemoteControlService: run: called
05-18 11:23:09.912 2319 2482 D RemoteControlService: getEvent: start waiting...
05-18 11:23:09.913 2319 6736 E RemoteControlService: Enter ListenSocketRunnable
05-18 11:23:09.913 2319 6736 D RemoteControlService: After desEncrypt json is [{"type":"power","source":0,"token":"Ni21TtH51HsNjC4","value":"click"}]
05-18 11:23:09.914 2319 6736 D RemoteControlService: buildRemoteCommand:type=5
05-18 11:23:09.914 2319 6736 D RemoteControlService: Request params: BaseRequestCommandBean{source=0, token='Ni21TtH51HsNjC4', type='power', value='click'}
05-18 11:23:09.914 2319 2471 D RemoteControlService: handleMessage called
05-18 11:23:09.914 2319 2471 D RemoteControlService: Client-192.168.4.4 handleHeartBeat:155
05-18 11:23:09.914 2319 2471 D RemoteControlService: Is not connect command
05-18 11:23:09.914 2319 2471 D RemoteControlService: haveControl ? clientcom.thundercomm.remotecontrolservice.RemoteControllerClient@8a41378
05-18 11:23:09.914 2319 2471 D RemoteControlService: Client have control
05-18 11:23:09.914 2319 2471 D RemoteControlService: do Action called
05-18 11:23:09.914 2319 2471 I RemoteControlService: injectKeyEvent: KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_POWER, scanCode=0, metaState=0, flags=0x0, repeatCount=0, eventTime=641101, downTime=641101, deviceId=-1, source=0x101, displayId=-1 }
05-18 11:23:09.917 1532 2979 I PowerManagerService: Powering on display group fromAsleep (groupId=0, uid=1000, reason=WAKE_REASON_POWER_BUTTON, details=android.policy:POWER)...
05-18 11:23:09.917 1532 2979 I PowerManagerService: Waking up from Asleep (uid=1000, reason=WAKE_REASON_POWER_BUTTON, details=android.policy:POWER)...
05-18 11:23:09.922 2319 2471 I RemoteControlService: injectKeyEvent: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_POWER, scanCode=0, metaState=0, flags=0x0, repeatCount=0, eventTime=641101, downTime=641101, deviceId=-1, source=0x101, displayId=-1 }
05-18 11:23:09.924 1532 1532 D WindowManager: powerPress: eventTime=641101 interactive=false count=0 beganFromNonInteractive=true mShortPressOnPowerBehavior=1
05-18 11:23:09.924 1867 1887 D KeyguardViewMediator: onStartedWakingUp, seq = 5
05-18 11:23:09.924 1867 1887 D KeyguardViewMediator: notifyStartedWakingUp
05-18 11:23:09.925 2319 2471 D RemoteControlService: Digest: F47AA2D3AD5F7BE51E92A438AB06DEAD30963DC0DE2C9FBC90FF46E1CB0202B4
05-18 11:23:09.925 1867 1867 D KeyguardViewMediator: handleNotifyWakingUp
05-18 11:23:09.925 2319 2471 D RemoteControlService: Send data length: 117
05-18 11:23:09.925 2319 2471 D RemoteControlService: Send message finished. direction: 16, messageType: 5, json: {"source":0,"token":"Ni21TtH51HsNjC4","type":"power","value":true}
05-18 11:23:09.926 2319 2471 D RemoteControlService: RemoteKeyCommand ResponseSpeedTest - use time: 13

中控在实现语音控制亮屏操作时，先查询副屏状态，若获取到的是息屏状态，则调用 POWER 键点亮屏幕，但是中控在执行查询的时候报错，也去调用了 POWER 键点亮屏幕，导致问题发生，从上面的回复（2）可知，该问题已经在中控端修复。

而回复（1）出现的 MessageReader: readFromServer: cant get data from service. 问题，是在遥控器在收到副屏的回复信息时，从 Socket 获取消息失败，原因是 Socket 接收超时，日志如下：

05-18 10:49:37.287 898 1783 I chatty : uid=0(root) FrontTask expire 17 lines
05-18 10:49:37.330 2844 4304 I HWHUD : I2C-will open i2c device node /dev/i2c-4
05-18 10:49:37.330 2844 4304 E HWHUD : I2C-open i2c device(/dev/i2c-4) fail
05-18 10:49:37.700 5520 5543 W System.err: java.net.SocketTimeoutException: Read timed out
05-18 10:49:37.702 5520 5543 W System.err: at java.net.SocketInputStream.socketRead0(Native Method)
05-18 10:49:37.702 5520 5543 W System.err: at java.net.SocketInputStream.socketRead(SocketInputStream.java:119)
05-18 10:49:37.702 5520 5543 W System.err: at java.net.SocketInputStream.read(SocketInputStream.java:176)
05-18 10:49:37.702 5520 5543 W System.err: at java.net.SocketInputStream.read(SocketInputStream.java:144)
05-18 10:49:37.702 5520 5543 W System.err: at java.net.SocketInputStream.read(SocketInputStream.java:130)
05-18 10:49:37.702 5520 5543 W System.err: at b.c.a(Unknown Source:1)
05-18 10:49:37.702 5520 5543 W System.err: at c.c.b(Unknown Source:21)
05-18 10:49:37.702 5520 5543 W System.err: at c.a.a(Unknown Source:2)
05-18 10:49:37.702 5520 5543 W System.err: at com.thundercomm.remotecontrol.RemoteControlManager$b.run(Unknown Source:2)
05-18 10:49:37.702 5520 5543 W System.err: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
05-18 10:49:37.702 5520 5543 W System.err: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
05-18 10:49:37.703 5520 5543 W System.err: at java.lang.Thread.run(Thread.java:923)
05-18 10:49:37.703 5520 5543 E RemoteControlClient_MessageReader: readFromServer: cant get data from service.
05-18 10:49:37.703 5520 5543 I HFSEM_REMOTE_CTRL: RemoteControlRepository-onError code=62;msg=Can not receive data from server.

问题可能是那个时间点的网络情况不稳定导致的超时。

结论：
1. 票的主题问题的发生是因为中控实现功能在查询副屏屏幕状态失败的情况下，任然调用了打开屏幕的命令。从回复可知，中控端已修复该问题；
2. 查询副屏屏幕状态失败是因为中控接收副屏的消息时 Socket 超时，从中控的日志中可以看出，中控遥控器多次调用连接命令，导致 Socket 异常；

■ Next action
天颖进一步确认问题 2 的原因。

#6 Updated by CD FW-廖涛 about 2 years ago

  • Category changed from 依赖客户及其供应商解决 to CD-FW
  • Status changed from NEED_INFO to ASSIGNED
  • Assignee changed from 物联网测试组_TSCD 王维 to CD FW-程天颖

#7 Updated by CD FW-程天颖 about 2 years ago

  • Root cause set to 1.语言控制在sdk连接成功的时候不应该再次连接,存在逻辑问题 2.遥控器服务端存在逻辑问题，在连接成功的时候，处理再次连接未回复消息

Hi，诗雨，
服务端在连接时再次连接进行了消息回复，将不再断连。该问题应该得到了处理，我的本地环境无法使用语言控制，所以无法进行验证。请帮使用最新的副屏我验证一下

#8 Updated by CD FW-程天颖 about 2 years ago

  • Assignee changed from CD FW-程天颖 to CDTS_Test 吴诗雨

#9 Updated by CDTS_TEST 王成 almost 2 years ago

  • Status changed from ASSIGNED to RESOLVED

验证通过。之前多个版本（110、116、118等）测试未复现此现象，关闭此问题。

#10 Updated by CDTS_TEST 王成 almost 2 years ago

  • Status changed from RESOLVED to VERIFIED

#11 Updated by CDTS_TEST 王成 almost 2 years ago

  • Status changed from VERIFIED to CLOSED

Also available in: Atom PDF