分布式设备连接对端失败问题分析
吐槽
这个是之前open Harmony 6.1release项目测试发现的问题,测试的应用是音乐的分布式流传,他提交了这个问题单以后,现在版本更新到6.1 LTS版本,需要把这个老问题重新测试一下。但是我拿到这个问题以后人都傻眼了,就说了一句连接失败,失败现象、失败在哪一步是一句没说。没办法,只能协调两块海思V900板子烧录重新弄搞了一周。最后看到最初的现象-----问题依然在6.1lts存在,失败在弹出是否允许连接到对端设备的弹窗上。
正常现象
当时WiFi模块有点问题,我采用的是网线直连组成局域网的方式进行调试。一端(source)打开音乐软件,在音乐软件的左下角有一个按钮,那个就是分布式流传功能,点击那个分布式流传,会弹出表单,里面会显示可进行连接的设备,点击连接对端设备(sink),source会提示请在对端完成确认,进入设备互信中的状态,sink会弹出一个窗口,大致意思是是否连接到对端设备,有取消、本次允许、始终允许三个选项,sink允许了以后,如果之前预制过白名单,是需要走haichain认证流程,sink弹窗pincode码,source弹窗输入窗,sink会将自己生成的pincode加密发送给source,source输入确认,校验通过了以后,source进入可分布式流转状态,这时候连接其实就建立成功了,点击互信设备(sink),sink就会拉起音乐软件,我的分布式软总线管的流程就到这了。
异常现象
是否连接到对端设备的弹窗都没弹出来,就超时失败了
分析流程
我刚开始接收软总线模块,流程我也不熟,再加上项目代码在很多关键位置是没有日志打印的,也就是说程序挂在哪个程序看不出来
第一次分析
这就是拿不到关键日志的盲目分析,我也忘了是怎么找到了第一次连接失败的日志,其实那个没啥用,挺丢人的,就是因为自己对流程也不熟悉导致的。是什么情况呢,正常流程:两个设备连接过程中,如果是预置在对端白名单或者之前是否连接到对端设备的时候选择了始终允许,是可以走快速认证,省略了pincode那个环节,也就是说按照我的测试情况,这个认证日志是一定失败的。他一定是要走第二次hichain认证。。。我当时不清楚就是卡在这里,还想这怎么打破这个死循环。会上社死。
第二次分析
在会上祖师爷的指点下,我搬出了祖师爷的分布式设备认证流程图,之前误判的死循环是卡在连接,还没到认证,后来纠正了,来到认证环节,我就按照流程图找关键日志来看,可是到是否连接到对端的附近的时候,我找不到日志了,项目中只有异常日志,都没打印,两端设备要连接,是需要先进行协商的,那个ondatareceived函数进入没都不知道,流程其实也是很乱。
第三次分析
看不到日志,就只能自己配环境拉项目加日志,搞了一天,就是这样第一次的吧关键日志拉取下来了,这是我当时的日志以及分析
正常现象:source端选择发起连接,sink端响应弹窗显示是否连接对端设备
异常现象:source端选择发起连接,sink端无响应
异常问题点:我已经将调用链相关函数都加上了自己的日志,auth_manager的onDataReceived没有触发记录
调用链:
底层 Socket 事件
↓
OnDataEvent (auth_tcp_connection.c:528)
↓
ProcessSocketInEvent (auth_tcp_connection.c:430)
↓
NotifyDataReceived (auth_tcp_connection.c:189)
↓
g_listener.onDataReceived → OnDataReceived (auth_manager.c:1704)
↓
根据 dataType 分发到不同处理函数
source端日志:
行 146185: 01-01 08:06:13.892 4126 4697 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 146186: 01-01 08:06:13.892 4126 4697 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 146188: 01-01 08:06:13.892 4126 4697 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 146246: 01-01 08:06:13.895 4126 4697 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 147653: 01-01 08:06:14.023 4126 4697 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 147654: 01-01 08:06:14.023 4126 4697 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 147656: 01-01 08:06:14.023 4126 4697 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 147659: 01-01 08:06:14.024 4126 4697 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 147667: 01-01 08:06:14.024 4115 4115 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] has enter,device_manager has received msg from softbus !
行 147673: 01-01 08:06:14.024 4115 4115 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] onbytesreceived has out , the next step is GetCurSession+GetAuthMgrByMessage+OnDataReceived
sink端日志:
行 42161: 01-01 08:06:30.805 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 42162: 01-01 08:06:30.805 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 42164: 01-01 08:06:30.805 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 42260: 01-01 08:06:30.814 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 43174: 01-01 08:06:31.029 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 43175: 01-01 08:06:31.029 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 43177: 01-01 08:06:31.030 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 43180: 01-01 08:06:31.030 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 43188: 01-01 08:06:31.030 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] has enter,device_manager has received msg from softbus !
行 43214: 01-01 08:06:31.037 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] onbytesreceived has out , the next step is GetCurSession+GetAuthMgrByMessage+OnDataReceived
行 44027: 01-01 08:06:31.144 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 44028: 01-01 08:06:31.144 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 44030: 01-01 08:06:31.145 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 44033: 01-01 08:06:31.145 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 44041: 01-01 08:06:31.145 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] has enter,device_manager has received msg from softbus !
行 44046: 01-01 08:06:31.146 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] onbytesreceived has out , the next step is GetCurSession+GetAuthMgrByMessage+OnDataReceived
行 104136: 01-01 08:07:31.147 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 104137: 01-01 08:07:31.147 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 104139: 01-01 08:07:31.147 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 104142: 01-01 08:07:31.148 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 104150: 01-01 08:07:31.149 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] has enter,device_manager has received msg from softbus !
行 104159: 01-01 08:07:31.149 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] onbytesreceived has out , the next step is GetCurSession+GetAuthMgrByMessage+OnDataReceived
行 104225: 01-01 08:07:31.158 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 104226: 01-01 08:07:31.158 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
C:\Users\Administrator\Desktop\分布式设备连接失败第二次\sink\hilog\hilog.028.19700101-080855\hilog.028.19700101-080855 (匹配 14 次)
行 106519: 01-01 08:09:05.873 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 106522: 01-01 08:09:05.873 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 107822: 01-01 08:09:05.927 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 107823: 01-01 08:09:05.927 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 107825: 01-01 08:09:05.927 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 107828: 01-01 08:09:05.927 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 107836: 01-01 08:09:05.928 4223 4335 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] has enter,device_manager has received msg from softbus !
行 107862: 01-01 08:09:05.930 4223 4335 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] onbytesreceived has out , the next step is GetCurSession+GetAuthMgrByMessage+OnDataReceived
行 109683: 01-01 08:09:06.038 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 109684: 01-01 08:09:06.038 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 109686: 01-01 08:09:06.038 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 109689: 01-01 08:09:06.039 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 109697: 01-01 08:09:06.039 4223 4335 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] has enter,device_manager has received msg from softbus !
行 109702: 01-01 08:09:06.039 4223 4335 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] onbytesreceived has out , the next step is GetCurSession+GetAuthMgrByMessage+OnDataReceived
C:\Users\Administrator\Desktop\分布式设备连接失败第二次\sink\hilog\hilog.033.19700101-081000\hilog.033.19700101-081000 (匹配 8 次)
行 69697: 01-01 08:10:06.045 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 69700: 01-01 08:10:06.045 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
行 69849: 01-01 08:10:06.049 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:192] NotifyDataReceived# [my][auth_tcp_connection.c][NotifyDataReceived] has enter
行 69854: 01-01 08:10:06.049 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:475] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has out , the next step is NotifyDataReceived
行 69863: 01-01 08:10:06.049 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] has enter,device_manager has received msg from softbus !
行 69884: 01-01 08:10:06.050 4223 4528 I C04110/DHDM: [devicemanagerserviceimpl][OnBytesReceived]:[my][device_manager_service_impl.cpp][OnBytesReceived] onbytesreceived has out , the next step is GetCurSession+GetAuthMgrByMessage+OnDataReceived
行 70051: 01-01 08:10:06.052 4225 4755 E C05723/AuthFsm: [auth_tcp_connection.c:537] OnDataEvent# [my][auth_tcp_connection.c][OnDataEvent] has enter
行 70052: 01-01 08:10:06.052 4225 4755 I C05723/AuthFsm: [auth_tcp_connection.c:436] ProcessSocketInEvent# [my][auth_tcp_connection.c][ProcessSocketInEvent] has enter
异常日志点:
在/home/liuyun/code/V900/6.1lts/foundation/communication/dsoftbus/core/authentication/src/auth_tcp_connection.c中的NotifyDataReceived函数进入后,函数最后会有onDataReceived,但是设置的日志没有触发,存在异常
这也是我第一次发现问题了,监听错了函数——sink 端实际执行的是 v2 框架的 AuthSinkManager::OnDataReceived,不是在 v1 dm_auth_manager.cpp 里加日志的那个。
void AuthSinkManager::OnDataReceived(int32_t sessionId, std::string message)
{
CHECK_NULL_VOID(context_);
context_->sessionId = sessionId;
int32_t ret = context_->authMessageProcessor->ParseMessage(context_, message);
if (ret != DM_OK) {
LOGE("OnDataReceived failed, parse input message error.");
context_->reason = ERR_DM_PARSE_MESSAGE_FAILED;
CHECK_NULL_VOID(context_->authStateMachine);
context_->authStateMachine->TransitionTo(std::make_shared<AuthSinkFinishState>());
}
return;
}
ShowConfigDialog (31.149) → ShowConfigDialog end (31.350)
→ DmDialogManager::ConnectExtension (31.163)
→ ConnectAbility(sceneboard) 失败 → "ConnectExtensionAbility sceneboard failed" (31.228) ← 决定性日志
→ (回退 systemui,你搜 "systemui failed again" 确认是否也失败)
→ 弹窗没有显示 → WaitExpectEvent(ON_USER_OPERATION) 空等
→ 60 秒后超时 → ON_FAIL → 52→66 → AuthSinkFinishState → 静默结束
→ source 端 60 秒重试,循环
| 层级 | 状态 | 依据 |
|---|---|---|
| DM 服务代码(device_manager) | 正常 | 弹窗调用正确发出:参数构造 → ConnectAbility → 失败后正确回退 systemui(dm_dialog_manager.cpp:186-224) |
| AAFwk 框架(系统能力服务) | 异常 | errCode=2097153(0x200001)是能力服务连接失败——ConnectAbility 这一步就返回非 0,DM 连 AAFwk 的通道都没通 |
| sceneboard / systemui(系统应用/弹窗宿主) | 未生效 | 根本没走到"弹窗显示",连接请求都没到达 |
证据链最强的对照实验已经有了:source 设备上 wallpaper 服务(同样是系统组件)调 ConnectExtensionAbility 也反复失败 errCode=2097153(19 次)。如果多个互不相关的组件都连不上能力服务,问题必然出在系统服务层(ability/sceneboard 服务栈)或镜像环境,而不是某个具体应用。
错误码2097153
0x200001 属于 AAFwk 错误域,含义是 Ability 服务连接失败(通常:AbilityManagerService 未就绪/连接被拒/bundle 未注册)。wallpaper 失败在 ConnectExtensionAbility:1265,DM 失败在 ConnectAbility——都在同一个 AAFwk 入口,同源。
问题闭环了,应用侧说参数有问题,打了一个新的hap包解决了,好消息是问题解决了,程序往后走了,点击本次允许,弹出pin码框,但是source没有弹出输入框!!!
锁屏问题
这个问题找出来的也快
PIN 码显示了但输入框没弹——日志已经把原因写得明明白白:IsScreenLocked isLocked: 1 → screen is locked → 认证直接结束。
int32_t AuthSrcPinInputState::ShowStartAuthDialog(std::shared_ptr<DmAuthContext> context)
{
LOGI("AuthSrcPinInputState::ShowStartAuthDialog start.");
if (DmAuthState::IsScreenLocked()) {
LOGE("AuthSrcPinInputState screen is locked.");
//暂时屏蔽,看看
//context->reason = ERR_DM_BIND_USER_CANCEL;
//return STOP_BIND;
}
context->listener->OnAuthResult(context->processInfo, context->peerTargetId.deviceId, context->accessee.tokenIdHash,
static_cast<int32_t>(STATUS_DM_SHOW_PIN_INPUT_UI), DM_OK);
context->listener->OnBindResult(context->processInfo, context->peerTargetId,
DM_OK, static_cast<int32_t>(STATUS_DM_SHOW_PIN_INPUT_UI), "");
DmDialogManager::GetInstance().ShowInputDialog(context->accessee.deviceName);
LOGI("AuthSrcPinInputState::ShowStartAuthDialog end.");
return DM_OK;
}
屏蔽掉以后流程可以继续往后走,这个问题暂时搁置,按照祖师爷的说法让系统侧去修改
输入PIN码后sink端未拉起
把锁屏问题屏蔽掉以后,输入pin码窗口弹出,但是输入以后等了一会就结束了,没有任何反馈,像是连接超时,直接没有后续了,正常source是会改变成点击进行分布式流转。
输入 PIN 后的认证链路(PIN 认证)
source(输入方) sink(显示方)
5 PIN_INPUT
├─ 输入PIN(DONE_PINCODE_INPUT)
├─→ 10 PIN_AUTH_START
│ └─发120(REQ_PIN_AUTH_START) ──────→ 59 PIN_AUTH_START:ProcessCredData(hiChain校验PIN)
│ ├─ WaitExpectEvent(ON_TRANSMIT)
11 MSG_NEGOTIATE:ProcessCredData └─发130(RESP_PIN_AUTH_START)
├─收130←──────────────────────────────┘
├─发121(REQ_PIN_AUTH_MSG_NEGOTIATE)──→ 60 MSG_NEGOTIATE:ProcessCredData→发131
12 PIN_AUTH_DONE
├─收131←──────────────────────────────┘
└─ WaitExpectEvent(ON_FINISH)──hiChain互信建立→成功→后续建信任/流转
关键:PIN 有效性由 hiChain 服务校验(两端 hiChainAuthConnector->ProcessCredData),DM 只负责驱动状态机。任何一环失败(hiChain 校验失败/服务异常、消息中断、60 秒超时)都会走 HandleAuthenticateTimeout → ON_FAIL → Finish → 应用回退到"点击开始设备互信"。
抓取清单:输入 PIN 后 60 秒内,两端各抓这些
source 端:
- 输入后
TransitionTo ... 10(5→10 正常走)和CreateAndSendMsg ... REQ_PIN_AUTH_START AuthSrcPinAuthMsgNegotiateState::Action start(收到 130 了吗?)AuthSrcPinAuthDoneState::Action(收到 131 了吗?wait ON_FINISH done?)- 失败信号:
HandleAuthenticateTimeout/Run err/ON_FINISH event not arriverd/TransitionTo ... 18
sink 端:
AuthSinkPinAuthStartState pinCodeHash: ...(收到 120,PIN 校验开始)AuthSinkPinAuthStartState::Action call ProcessCredData err(hiChain 失败 → 直接定位)WaitExpectEvent ON_TRANSMIT/ON_ERROR结果HandleAuthenticateTimeout/Run err/TransitionTo ... 66
两端通用:
DmAuthStateMachine: The state transition from X to Y(完整状态流,看卡在哪、往哪回退)deviceManagerTimer:waitPinAuth(60 秒超时定时器启动/触发)- hiChain 服务日志(
hichain/DHC域)——重点:之前 sceneboard/ability 服务都异常过,如果 hiChain 服务也不健康,ProcessCredData会失败,这是最可疑的候选
原日志
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\source\hilog\hilog.107.19700101-082823\hilog.107.19700101-082823 (匹配 3 次)
行 63372: 01-01 08:28:27.614 4349 21273 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 0 to 1.
行 63384: 01-01 08:28:27.614 4349 21273 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 1 to 2.
行 66043: 01-01 08:28:27.692 4349 4572 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 2 to 3.
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\source\hilog\hilog.108.19700101-082831\hilog.108.19700101-082831 (匹配 5 次)
行 34333: 01-01 08:28:32.545 4349 4349 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 3 to 4.
行 34356: 01-01 08:28:32.546 4349 21274 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 4 to 5.
行 50516: 01-01 08:28:33.065 4112 4719 D C04200/StateMachine: [a92abd06b09e5fd, 11b4556, 22039b2] TransitionTo: system window no need to use stateMachine
行 83587: 01-01 08:28:34.027 4112 4719 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 105744: 01-01 08:28:34.587 4112 4719 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\source\hilog\hilog.115.19700101-082904\hilog.115.19700101-082904 (匹配 2 次)
行 44616: 01-01 08:29:05.620 4112 4719 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 99807: 01-01 08:29:07.352 4112 4719 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\source\hilog\hilog.119.19700101-082928\hilog.119.19700101-082928 (匹配 3 次)
行 94467: 01-01 08:29:32.546 4349 5223 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 5 to 18.
行 94471: 01-01 08:29:32.546 4349 21274 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.003.19700101-080329\hilog.003.19700101-080329 (匹配 1 次)
行 41462: 01-01 08:03:31.767 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.005.19700101-080532\hilog.005.19700101-080532 (匹配 3 次)
行 71869: 01-01 08:06:23.321 4414 8155 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 0 to 1.
行 71875: 01-01 08:06:23.321 4414 8155 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 1 to 2.
行 73336: 01-01 08:06:23.406 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 2 to 3.
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.006.19700101-080627\hilog.006.19700101-080627 (匹配 5 次)
行 19959: 01-01 08:06:28.247 4414 5243 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 3 to 4.
行 19991: 01-01 08:06:28.247 4414 8156 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 4 to 5.
行 34574: 01-01 08:06:28.795 4291 4843 D C04200/StateMachine: [a92ab301844d443, 3047520, 315af65] TransitionTo: system window no need to use stateMachine
行 69041: 01-01 08:06:29.909 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 121809: 01-01 08:06:31.589 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.009.19700101-080644\hilog.009.19700101-080644 (匹配 14 次)
行 42869: 01-01 08:06:45.716 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 5 to 18.
行 42873: 01-01 08:06:45.716 4414 4467 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 42881: 01-01 08:06:45.716 4414 8156 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 46957: 01-01 08:06:45.809 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 54923: 01-01 08:06:45.984 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 95469: 01-01 08:07:03.950 4414 5243 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 0 to 51.
行 96604: 01-01 08:07:04.046 4414 5243 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 51 to 52.
行 102142: 01-01 08:07:04.490 4291 4843 D C04200/StateMachine: [a92ab501a81f1ec, 128bca9, 1b6db6d] TransitionTo: system window no need to use stateMachine
行 124188: 01-01 08:07:05.448 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 136706: 01-01 08:07:07.438 4414 8696 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 52 to 53.
行 136748: 01-01 08:07:07.440 4414 8696 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 53 to 54.
行 137729: 01-01 08:07:07.466 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.010.19700101-080707\hilog.010.19700101-080707 (匹配 9 次)
行 6: 01-01 08:07:07.669 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 22112: 01-01 08:07:08.603 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 90571: 01-01 08:08:07.441 4414 5174 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 54 to 66.
行 90626: 01-01 08:08:07.444 4414 5243 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 90627: 01-01 08:08:07.444 4414 5243 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 92288: 01-01 08:08:07.522 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 96370: 01-01 08:08:07.598 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.011.19700101-080850\hilog.011.19700101-080850 (匹配 8 次)
行 8612: 01-01 08:08:58.871 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 0 to 51.
行 9434: 01-01 08:08:58.982 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 51 to 52.
行 15001: 01-01 08:08:59.431 4291 4843 D C04200/StateMachine: [a92ab7021b11bcb, 7678e9, 293764a] TransitionTo: system window no need to use stateMachine
行 35670: 01-01 08:09:00.402 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 56709: 01-01 08:09:05.577 4414 10030 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 52 to 53.
行 56770: 01-01 08:09:05.579 4414 10030 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 53 to 54.
行 58071: 01-01 08:09:05.610 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 89266: 01-01 08:09:06.760 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.012.19700101-080955\hilog.012.19700101-080955 (匹配 7 次)
行 11119: 01-01 08:10:05.580 4414 5174 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 54 to 66.
行 11172: 01-01 08:10:05.583 4414 5243 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 11173: 01-01 08:10:05.583 4414 5243 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 12353: 01-01 08:10:05.662 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 17247: 01-01 08:10:05.757 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.013.19700101-081121\hilog.013.19700101-081121 (匹配 3 次)
行 140881: 01-01 08:12:48.744 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 0 to 51.
行 141783: 01-01 08:12:48.857 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 51 to 52.
行 146900: 01-01 08:12:49.266 4291 4843 D C04200/StateMachine: [a92ab90300e47ed, 26640dc, 22b710a] TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.014.19700101-081249\hilog.014.19700101-081249 (匹配 8 次)
行 20240: 01-01 08:12:50.247 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 34992: 01-01 08:12:52.858 4414 12633 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 52 to 53.
行 35050: 01-01 08:12:52.860 4414 12633 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 53 to 54.
行 35833: 01-01 08:12:52.890 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 36994: 01-01 08:12:52.910 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 47734: 01-01 08:12:53.114 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 139781: 01-01 08:13:52.861 4414 5177 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 54 to 66.
行 141231: 01-01 08:13:52.937 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.015.19700101-081353\hilog.015.19700101-081353 (匹配 10 次)
行 49417: 01-01 08:14:36.966 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 0 to 51.
行 50267: 01-01 08:14:37.079 4414 4467 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 51 to 52.
行 55258: 01-01 08:14:37.507 4291 4843 D C04200/StateMachine: [a92abb036d26085, 669e62, 2414c3a] TransitionTo: system window no need to use stateMachine
行 76730: 01-01 08:14:38.440 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 94522: 01-01 08:14:42.217 4414 13874 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 52 to 53.
行 94565: 01-01 08:14:42.218 4414 13874 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 53 to 54.
行 95219: 01-01 08:14:42.241 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 96122: 01-01 08:14:42.253 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 103178: 01-01 08:14:42.365 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 126536: 01-01 08:14:43.384 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.018.19700101-081818\hilog.018.19700101-081818 (匹配 8 次)
行 62249: 01-01 08:19:05.677 4414 5243 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 0 to 51.
行 63337: 01-01 08:19:05.799 4414 5243 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 51 to 52.
行 68456: 01-01 08:19:06.236 4291 4843 D C04200/StateMachine: [a92abd0479d6814, cac847, 24a3297] TransitionTo: system window no need to use stateMachine
行 90992: 01-01 08:19:07.191 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 110144: 01-01 08:19:10.594 4414 16901 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 52 to 53.
行 110204: 01-01 08:19:10.596 4414 16901 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 53 to 54.
行 110942: 01-01 08:19:10.618 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 120136: 01-01 08:19:10.831 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
C:\Users\Administrator\Desktop\分布式设备连接失败第三次\sink\hilog\hilog.019.19700101-081913\hilog.019.19700101-081913 (匹配 7 次)
行 89902: 01-01 08:20:10.596 4414 5174 I C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine: The state transition from 54 to 66.
行 89970: 01-01 08:20:10.600 4414 4465 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 89972: 01-01 08:20:10.600 4414 4465 E C04110/DHDM: [devicemanagerserviceimpl][TransitionTo]:DmAuthStateMachine::TransitionTo next state is invalid.
行 91616: 01-01 08:20:10.635 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
行 96082: 01-01 08:20:10.717 4291 4843 D C04200/StateMachine: TransitionTo: system window no need to use stateMachine
本次状态流还原(source 4349 / sink 4414)
source: 08:28:27.6 0→1→2 08:28:27.7 2→3(收90发100)
08:28:32.5 3→4→5(PIN输入框弹出)
08:29:32.5 5→18(恰好60秒!)← 输入事件没到状态机,干等超时
sink: 08:06:23 0→1→2→3 08:06:28 3→4→5
08:07:03 0→51→52(确认)→53→54(PIN码显示)
08:08:07 54→66(恰好60秒)← 等 source 的120消息,没等到
source 的 5(PIN_INPUT)在 60 秒整后 5→18 结束,没有任何 5→10(PIN_AUTH_START)转换 —— 说明用户输入 PIN 后,ON_USER_OPERATION 事件从未到达状态机。sink 的 54→66 只是果(source 没发 120)。
断点:UI 输入框 → DM 状态机的回调链
输入框 UI(sceneboard PIN输入组件)
→ SetUserOperation(action=DONE_PINCODE_INPUT, params={"pinCode":"..."}) device_manager_service_impl.cpp:733
→ GetCurrentAuthMgr() :487
→ authMgr->OnUserOperation(action, params) auth_manager.cpp:948
→ pinInputResult = DONE_PINCODE_INPUT
→ 解析 pinCode(失败则 return,不通知状态机!) ← 注意:解析失败是静默断点
→ NotifyEventFinish(ON_USER_OPERATION) ← 没触发的话状态机等满60秒
下一步:抓 source 端这几个日志(输入 PIN 后的 60 秒内)
AuthSrcManager::OnUserOperation start—— 没有 = 回调根本没到 DM(问题在 UI 输入框→DM 的 IPC 链路);有 = 继续看下一条AuthSrcManager OnUserOperation user input done/user cancel—— 判断 action 是否到了OnUserOperation jsonStr error/pinCode not found—— 有 = pinCode 解析失败(断点 2)NotifyEventFinish Event:8(ON_USER_OPERATION=8)—— 有 = 事件已推入,那就要怀疑状态机 5 的 WaitExpectEvent 是否在等(和定时器竞争)
就找到了pinCode not found日志foundation/distributedhardware/device_manager/services/implementation/src/authentication_v2/auth_manager.cpp
case USER_OPERATION_TYPE_DONE_PINCODE_INPUT:
LOGE("AuthSrcManager OnUserOperation user input done");
context_->pinInputResult = USER_OPERATION_TYPE_DONE_PINCODE_INPUT;
if (paramJson.IsDiscarded() || !IsString(paramJson, PIN_CODE_KEY)) {
LOGE("AuthSrcManager OnUserOperation pinCode not found");
return ERR_DM_INPUT_PARA_INVALID;
}
pinCode = paramJson[PIN_CODE_KEY].Get<std::string>();
{
if (!IsNumberString(pinCode)) {
LOGE("OnUserOperation jsonStr error");
return ERR_DM_INPUT_PARA_INVALID;
}
context_->pinCode = pinCode;
}
context_->authStateMachine->NotifyEventFinish(DmEventType::ON_USER_OPERATION);
break;
default:
LOGE("this action id not support");
break;
}
LOGI("AuthSrcManager::OnUserOperation leave.");
return DM_OK;
}
PIN_CODE_KEY = "pinCode"(dm_constants.cpp:63),且要求是字符串类型。pinCode not found 意味着 UI 传的 params 里:要么不是合法 JSON,要么 pinCode key 缺失,要么值是数字类型("pinCode":123456 而不是 "pinCode":"123456")——IsString 会 false。
归属:输入框 UI(调用方应用)的参数构造问题
SetUserOperation(action, params) 的 params 由输入框 UI 组件(sceneboard PIN 输入组件 / 你的 App 侧 UI)在输入完成后构造并通过 ohos.distributedDeviceManager 回调(ohos.distributedDeviceManager.cpp:319)。UI 侧代码不在这个仓库(在应用工程/系统 UI 组件里),需要应用侧查输入框回调处 SetUserOperation 第二个参数的 JSON 内容。setuseroperation现在走的是ReplyUiAction
void DeviceManagerImpl::ReplyUiAction(int32_t action, ::taihe::string_view actionResult)
{
if (!IsInit()) {
ani_errorutils::CreateBusinessError(DM_ERR_FAILED);
return;
}
if (!IsSystemApp()) {
LOGE("ReplyUiAction not SystemApp");
ani_errorutils::CreateBusinessError(DMBusinessErrorCode::ERR_NOT_SYSTEM_APP);
return;
}
bool checkRet = ani_dmutils::CheckJsParamStringValid(std::string(actionResult));
if (!checkRet) {
return;
}
int32_t ret = DeviceManager::GetInstance().SetUserOperation(bundleName_, action, std::string(actionResult));
if (ret != 0) {
LOGE("SetUserOperation for bundleName %{public}s failed, ret %{public}d", bundleName_.c_str(), ret);
ani_errorutils::CreateBusinessError(ret);
}
}
但是在软总线侧,需要的还是老的json风格键值对{"pinCode":"数字"},应用侧传过来的是字符串

这就对不上了,这时候我的祖师爷出手帮我和应用侧对齐,有两个方案,一个是应用侧向底层对齐(优先),一个是底层直接把json解析环节去掉。
最终整个流程闭环了,就剩一个锁屏问题,收获还是挺大的,加日志,调试,烧录,团队支援,流程图v2的诞生,才能让问题处理的这么顺利。
更多推荐
所有评论(0)