吐槽

这个是之前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: 1screen 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 秒内)

  1. AuthSrcManager::OnUserOperation start —— 没有 = 回调根本没到 DM(问题在 UI 输入框→DM 的 IPC 链路);有 = 继续看下一条
  2. AuthSrcManager OnUserOperation user input done / user cancel —— 判断 action 是否到了
  3. OnUserOperation jsonStr error / pinCode not found —— 有 = pinCode 解析失败(断点 2)
  4. 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的诞生,才能让问题处理的这么顺利。

Logo

开源鸿蒙跨平台开发社区汇聚开发者与厂商,共建“一次开发,多端部署”的开源生态,致力于降低跨端开发门槛,推动万物智联创新。

更多推荐