diff --git a/common/include/input_hub.cpp b/common/include/input_hub.cpp index 0e3f068eed6f15fb4678f8ad9809c587ff9ba311..426b155c601bd5b34a41a15644fe713ffaf0006c 100644 --- a/common/include/input_hub.cpp +++ b/common/include/input_hub.cpp @@ -107,7 +107,7 @@ bool InputHub::IsInputNodeNoNeedScan(const std::string &path) } if (path.find(MOUSE_NODE_KEY) != std::string::npos) { - DHLOGI("Skip mouse node for no permission, path: %s", path.c_str()); + DHLOGD("Skip mouse node for no permission, path: %s", path.c_str()); return true; } @@ -116,7 +116,7 @@ bool InputHub::IsInputNodeNoNeedScan(const std::string &path) void InputHub::ScanAndRecordInputDevices() { - DHLOGI("Scan local input devices."); + DHLOGD("Scan local input devices."); ScanInputDevices(DEVICE_PATH); { @@ -180,7 +180,7 @@ size_t InputHub::GetEvents(RawEvent *buffer, size_t bufferSize) } if (!sharedDHIds_[device->identifier.descriptor]) { RecordDeviceChangeStates(device, readBuffer, count); - DHLOGE("Not in sharing stat, device descriptor: %s", + DHLOGD("Not in sharing stat, device descriptor: %s", GetAnonyString(device->identifier.descriptor).c_str()); continue; } @@ -204,7 +204,7 @@ size_t InputHub::GetEvents(RawEvent *buffer, size_t bufferSize) bool InputHub::IsTouchPad(const InputDevice &inputDevice) { std::string dhName = inputDevice.name; - DHLOGI("device name is %s.", dhName.c_str()); + DHLOGD("device name is %s.", dhName.c_str()); transform(dhName.begin(), dhName.end(), dhName.begin(), ::tolower); if (dhName.find(DH_TOUCH_PAD) == std::string::npos) { return false; @@ -473,12 +473,12 @@ std::vector InputHub::GetAllInputDevices() void InputHub::ScanInputDevices(const std::string &dirName) { - DHLOGI("ScanInputDevices enter, dirName %s.", dirName.c_str()); + DHLOGD("ScanInputDevices enter, dirName %s.", dirName.c_str()); std::vector inputDevPaths; ScanInputDevicesPath(dirName, inputDevPaths); for (const auto &tempPath: inputDevPaths) { if (IsInputNodeNoNeedScan(tempPath)) { - DHLOGI("This input node path should skip. Path: %s", tempPath.c_str()); + DHLOGD("This input node path should skip. Path: %s", tempPath.c_str()); continue; } OpenInputDeviceLocked(tempPath); @@ -504,7 +504,7 @@ int32_t InputHub::OpenInputDeviceLocked(const std::string &devicePath) } std::lock_guard my_lock(operationMutex_); - DHLOGI("Opening device start: %s", devicePath.c_str()); + DHLOGD("Opening device start: %s", devicePath.c_str()); int fd = OpenInputDeviceFdByPath(devicePath); if (fd == UN_INIT_FD_VALUE) { DHLOGE("The fd open failed, devicePath %s.", devicePath.c_str()); @@ -550,8 +550,7 @@ int32_t InputHub::QueryInputDeviceInfo(int fd, std::unique_ptr &device) char buffer[INPUT_EVENT_BUFFER_SIZE] = {0}; // Get device name. if (ioctl(fd, EVIOCGNAME(sizeof(buffer) - 1), &buffer) < 1) { - DHLOGE( - "Could not get device name for %s", ConvertErrNo().c_str()); + DHLOGE("Could not get device name for %s", ConvertErrNo().c_str()); } else { buffer[sizeof(buffer) - 1] = '\0'; device->identifier.name = buffer; @@ -559,6 +558,7 @@ int32_t InputHub::QueryInputDeviceInfo(int fd, std::unique_ptr &device) DHLOGD("QueryInputDeviceInfo deviceName: %s", buffer); // If the device is already a virtual device, don't monitor it. if (device->identifier.name.find(VIRTUAL_DEVICE_NAME) != std::string::npos) { + DHLOGE("this is a virtual driver, skip it."); RecordSkipDevicePath(device->path); return ERR_DH_INPUT_HUB_IS_VIRTUAL_DEVICE; } @@ -566,12 +566,14 @@ int32_t InputHub::QueryInputDeviceInfo(int fd, std::unique_ptr &device) int driverVersion; if (ioctl(fd, EVIOCGVERSION, &driverVersion)) { DHLOGE("could not get driver version for %s\n", ConvertErrNo().c_str()); + RecordSkipDevicePath(device->path); return ERR_DH_INPUT_HUB_QUERY_INPUT_DEVICE_INFO_FAIL; } // Get device identifier. struct input_id inputId; if (ioctl(fd, EVIOCGID, &inputId)) { DHLOGE("could not get device input id for %s\n", ConvertErrNo().c_str()); + RecordSkipDevicePath(device->path); return ERR_DH_INPUT_HUB_QUERY_INPUT_DEVICE_INFO_FAIL; } device->identifier.bus = inputId.bustype; @@ -715,7 +717,7 @@ int32_t InputHub::GetEventKeys(struct libevdev *dev, InputDevice &identifier) DHLOGD("The device is not support eventKey: %d", eventKey); continue; } - DHLOGI("QueryInputDeviceInfo eventKey: %d", eventKey); + DHLOGD("QueryInputDeviceInfo eventKey: %d", eventKey); identifier.eventKeys.push_back(eventKey); } return DH_SUCCESS; @@ -1091,11 +1093,11 @@ InputHub::Device* InputHub::GetDeviceByFdLocked(int fd) InputHub::Device* InputHub::GetSupportDeviceByFd(int fd) { - DHLOGI("GetSupportDeviceByFd fd: %d", fd); + DHLOGD("GetSupportDeviceByFd fd: %d", fd); std::lock_guard deviceLock(devicesMutex_); for (const auto &[id, device] : devices_) { if (device != nullptr && device->fd == fd) { - DHLOGI("GetSupportDeviceByFd device fd: %d, path: %s, dhId: %s, classes=0x%x", device->fd, + DHLOGD("GetSupportDeviceByFd device fd: %d, path: %s, dhId: %s, classes=0x%x", device->fd, device->path.c_str(), GetAnonyString(device->identifier.descriptor).c_str(), device->classes); return device.get(); } @@ -1312,7 +1314,7 @@ void InputHub::RecordChangeEventLog(const RawEvent &event) eventType = "other type " + std::to_string(event.type); break; } - DHLOGD("0.E2E-Test Sink collect change event, EventType: %s, Code: %d, Value: %d, Path: %s, descriptor: %s," + DHLOGI("0.E2E-Test Sink collect change event, EventType: %s, Code: %d, Value: %d, Path: %s, descriptor: %s," "When:%" PRId64 "", eventType.c_str(), event.code, event.value, event.path.c_str(), GetAnonyString(event.descriptor).c_str(), event.when); } @@ -1550,7 +1552,7 @@ InputHub::Device::Device(int fd, const std::string &path) : next(nullptr), fd(fd), path(path), identifier({}), classes(0), enabled(false), isShare(false), isVirtual(fd < 0) { // Figure out the kinds of events the device reports. - DHLOGE("Ctor Device for get event mask, fd: %d, path: %s", fd, path.c_str()); + DHLOGI("Ctor Device for get event mask, fd: %d, path: %s", fd, path.c_str()); ioctl(fd, EVIOCGBIT(0, sizeof(evBitmask)), evBitmask); ioctl(fd, EVIOCGBIT(EV_KEY, sizeof(keyBitmask)), keyBitmask); ioctl(fd, EVIOCGBIT(EV_ABS, sizeof(absBitmask)), absBitmask); diff --git a/services/sink/inputcollector/src/distributed_input_collector.cpp b/services/sink/inputcollector/src/distributed_input_collector.cpp index 52015c0ecd4be735ed946b089522765c75307074..e70c1988b4e115d38c8eb977660a9ae17c9b3feb 100644 --- a/services/sink/inputcollector/src/distributed_input_collector.cpp +++ b/services/sink/inputcollector/src/distributed_input_collector.cpp @@ -117,7 +117,7 @@ void DistributedInputCollector::StartCollectEventsThread() } size_t count = inputHub_->StartCollectInputEvents(mEventBuffer, INPUT_EVENT_BUFFER_SIZE); if (count > 0) { - DHLOGI("Count: %zu", count); + DHLOGD("Count: %zu", count); } else { continue; } diff --git a/services/sink/transport/src/distributed_input_sink_transport.cpp b/services/sink/transport/src/distributed_input_sink_transport.cpp index 0025ea3d3eb1115e57972e3575513bb73c66da0b..69368ca13c47c20d1df4f5ccf6e4bbd497eff066 100644 --- a/services/sink/transport/src/distributed_input_sink_transport.cpp +++ b/services/sink/transport/src/distributed_input_sink_transport.cpp @@ -69,7 +69,7 @@ DistributedInputSinkTransport &DistributedInputSinkTransport::GetInstance() void DistributedInputSinkTransport::DInputSinkEventHandler::ProcessEvent(const AppExecFwk::InnerEvent::Pointer &event) { - DHLOGI("ProcessEvent"); + DHLOGD("ProcessEvent"); EHandlerMsgType eventId = static_cast(event->GetInnerEventId()); switch (eventId) { case EHandlerMsgType::DINPUT_SINK_EVENT_HANDLER_MSG: { @@ -199,7 +199,7 @@ int32_t DistributedInputSinkTransport::RespLatency(const int32_t sessionId, std: return ERR_DH_INPUT_SERVER_SINK_TRANSPORT_RESP_LATENCY_FAIL; } - DHLOGI("RespLatency sessionId: %d, smsg:%s.", sessionId, SetAnonyId(smsg).c_str()); + DHLOGD("RespLatency sessionId: %d, smsg:%s.", sessionId, SetAnonyId(smsg).c_str()); return DH_SUCCESS; } @@ -234,7 +234,7 @@ void DistributedInputSinkTransport::SendKeyStateNodeMsgBatch(const int32_t sessi } DHLOGI("SendKeyStateNodeMsgBatch sessionId: %d, event size: %d ", sessionId, events.size()); - int64_t currentTimeNs = GetCurrentTime() * 1000LL; + int64_t currentTimeNs = GetCurrentTimeUs() * 1000LL; std::shared_ptr eventsJsonArr = std::make_shared(); for (const auto &ev : events) { nlohmann::json tmpJson; diff --git a/services/source/inputinject/src/distributed_input_node_manager.cpp b/services/source/inputinject/src/distributed_input_node_manager.cpp index 2c59710e815a96c13ffb6dd7ed9b17e20eb4a1e4..a429a984a1ec1c2ba1a4cd34e4b9f63210a8d6c6 100644 --- a/services/source/inputinject/src/distributed_input_node_manager.cpp +++ b/services/source/inputinject/src/distributed_input_node_manager.cpp @@ -471,7 +471,7 @@ void DistributedInputNodeManager::InjectEvent() if (ret != 0) { DHLOGE("InjectEvent setname failed."); } - DHLOGI("start"); + DHLOGD("start"); while (isInjectThreadRunning_.load()) { EventBatch events; { @@ -488,7 +488,7 @@ void DistributedInputNodeManager::InjectEvent() DHLOGD("process event, inject queue size: %zu", injectQueue_.size()); ProcessInjectEvent(events); } - DHLOGI("end"); + DHLOGD("end"); } void DistributedInputNodeManager::RegisterInjectEventCb(sptr callback) diff --git a/services/source/sourcemanager/src/dinput_source_listener.cpp b/services/source/sourcemanager/src/dinput_source_listener.cpp index 5aadc16d19a7d88b6b283152dd099cc2d371374d..c35328d16283dc481d6675d135d60149557f5e42 100644 --- a/services/source/sourcemanager/src/dinput_source_listener.cpp +++ b/services/source/sourcemanager/src/dinput_source_listener.cpp @@ -346,7 +346,7 @@ void DInputSourceListener::OnReceivedEventRemoteInput(const std::string deviceId } size_t jsonSize = inputData.size(); - DHLOGI("OnReceivedEventRemoteInput called, deviceId: %s, json size:%d.", + DHLOGD("OnReceivedEventRemoteInput called, deviceId: %s, json size:%d.", GetAnonyString(deviceId).c_str(), jsonSize); std::vector mEventBuffer(jsonSize); diff --git a/services/source/transport/src/distributed_input_source_transport.cpp b/services/source/transport/src/distributed_input_source_transport.cpp index a10823b6ce8a101d421600669d76029c98fae450..e6c370e92e0a379b7bdcc75c788c161df557c1cd 100644 --- a/services/source/transport/src/distributed_input_source_transport.cpp +++ b/services/source/transport/src/distributed_input_source_transport.cpp @@ -41,6 +41,7 @@ namespace DistributedHardware { namespace DistributedInput { namespace { const char DHID_SPLIT = '.'; + const uint64_t MSG_LATENCY_ALARM_US = 20 * 1000; } DistributedInputSourceTransport::~DistributedInputSourceTransport() { @@ -673,7 +674,7 @@ void DistributedInputSourceTransport::StartLatencyCount(const std::string &devic recvNum_ = 0; eachLatencyDetails_ = ""; } - sendTime_ = GetCurrentTime(); + sendTime_ = GetCurrentTimeUs(); LatencyCount(deviceId); sendNum_ += 1; usleep(INPUT_LATENCY_DELAYTIME_US); @@ -1077,7 +1078,7 @@ void DistributedInputSourceTransport::NotifyResponseKeyStateBatch(int32_t sessio void DistributedInputSourceTransport::NotifyReceivedEventRemoteInput(int32_t sessionId, const nlohmann::json &recMsg) { - DHLOGI("OnBytesReceived cmdType is TRANS_SINK_MSG_BODY_DATA."); + DHLOGD("OnBytesReceived cmdType is TRANS_SINK_MSG_BODY_DATA."); if (!IsString(recMsg, DINPUT_SOFTBUS_KEY_INPUT_DATA)) { DHLOGE("The key is invaild."); return; @@ -1094,17 +1095,20 @@ void DistributedInputSourceTransport::NotifyReceivedEventRemoteInput(int32_t ses void DistributedInputSourceTransport::CalculateLatency(int32_t sessionId, const nlohmann::json &recMsg) { - DHLOGI("OnBytesReceived cmdType is TRANS_SINK_MSG_LATENCY."); + DHLOGD("OnBytesReceived cmdType is TRANS_SINK_MSG_LATENCY."); std::string deviceId = DistributedInputTransportBase::GetInstance().GetDevIdBySessionId(sessionId); if (deviceId.empty()) { DHLOGE("OnBytesReceived cmdType is TRANS_SINK_MSG_LATENCY, deviceId is error."); return; } - deltaTime_ = GetCurrentTime() - sendTime_; + deltaTime_ = GetCurrentTimeUs() - sendTime_; deltaTimeAll_ += deltaTime_; recvNum_ += 1; eachLatencyDetails_ += (std::to_string(deltaTime_) + DINPUT_SPLIT_COMMA); + if (deltaTime_ >= MSG_LATENCY_ALARM_US) { + DHLOGW("The RTT time between send req and receive rsp is too long: %llu us", deltaTime_); + } } void DistributedInputSourceTransport::ReceiveSrcTSrcRelayPrepare(int32_t sessionId, const nlohmann::json &recMsg) diff --git a/services/transportbase/src/distributed_input_transport_base.cpp b/services/transportbase/src/distributed_input_transport_base.cpp index 1791dd51072f77078e26df98e88f10604e431496..f89b47f9cfe206f3c240e7d0b7e25cc3016becbe 100644 --- a/services/transportbase/src/distributed_input_transport_base.cpp +++ b/services/transportbase/src/distributed_input_transport_base.cpp @@ -443,7 +443,7 @@ bool DistributedInputTransportBase::CheckRecivedData(const std::string &message) void DistributedInputTransportBase::OnBytesReceived(int32_t sessionId, const void *data, uint32_t dataLen) { - DHLOGI("OnBytesReceived, sessionId: %d, dataLen:%d", sessionId, dataLen); + DHLOGD("OnBytesReceived, sessionId: %d, dataLen:%d", sessionId, dataLen); if (sessionId < 0 || data == nullptr || dataLen <= 0) { DHLOGE("OnBytesReceived param check failed"); return; @@ -462,11 +462,11 @@ void DistributedInputTransportBase::OnBytesReceived(int32_t sessionId, const voi } std::string message(buf, buf + dataLen); - DHLOGI("OnBytesReceived message:%s.", SetAnonyId(message).c_str()); + DHLOGD("OnBytesReceived message:%s.", SetAnonyId(message).c_str()); HandleSession(sessionId, message); free(buf); - DHLOGI("OnBytesReceived completed"); + DHLOGD("OnBytesReceived completed"); return; } @@ -485,13 +485,13 @@ void DistributedInputTransportBase::HandleSession(int32_t sessionId, const std:: return; } uint32_t cmdType = recMsg[DINPUT_SOFTBUS_KEY_CMD_TYPE]; - DHLOGI("HandleSession cmdType %u.", cmdType); + DHLOGD("HandleSession cmdType %u.", cmdType); if (cmdType < TRANS_MSG_SRC_SINK_SPLIT) { if (srcCallback_ == nullptr) { DHLOGE("srcCallback is nullptr."); return; } - DHLOGI("HandleSession to source."); + DHLOGD("HandleSession to source."); srcCallback_->HandleSessionData(sessionId, message); return; } @@ -500,7 +500,7 @@ void DistributedInputTransportBase::HandleSession(int32_t sessionId, const std:: DHLOGE("sinkCallback is nullptr."); return; } - DHLOGI("HandleSession to sink."); + DHLOGD("HandleSession to sink."); sinkCallback_->HandleSessionData(sessionId, message); } } diff --git a/utils/include/dinput_utils_tool.h b/utils/include/dinput_utils_tool.h index b41e56450a8738d54056e1b459f4f90d0961a7f5..15ab0ad2ff0417f3f0643af159bc7712e627d158 100644 --- a/utils/include/dinput_utils_tool.h +++ b/utils/include/dinput_utils_tool.h @@ -36,7 +36,7 @@ struct DevInfo { DevInfo GetLocalDeviceInfo(); std::string GetLocalNetworkId(); std::string GetUUIDBySoftBus(const std::string &networkId); -uint64_t GetCurrentTime(); +uint64_t GetCurrentTimeUs(); std::string SetAnonyId(const std::string &message); /* IsString, IsUInt32 and IsUInt64 are used to valid json key */ bool IsBoolean(const nlohmann::json &jsonObj, const std::string &key); diff --git a/utils/src/dinput_utils_tool.cpp b/utils/src/dinput_utils_tool.cpp index bb0b59cf6f756d58c44e5f3d53b72ede0a3df61d..ecd2273e2e07c171f01dcec7733ebaad18e6023e 100644 --- a/utils/src/dinput_utils_tool.cpp +++ b/utils/src/dinput_utils_tool.cpp @@ -95,7 +95,7 @@ std::string GetUUIDBySoftBus(const std::string &networkId) return (ret == DH_SUCCESS) ? std::string(uuid) : ""; } -uint64_t GetCurrentTime() +uint64_t GetCurrentTimeUs() { constexpr int32_t usOneSecond = 1000 * 1000; struct timeval tv; @@ -351,7 +351,7 @@ void ScanInputDevicesPath(const std::string &dirName, std::vector & continue; } std::string tmpDevName = dirName + "/" + std::string(de->d_name); - DHLOGI("Find input node path: %s", tmpDevName.c_str()); + DHLOGD("Find input node path: %s", tmpDevName.c_str()); vecInputDevPath.push_back(tmpDevName); } closedir(dir); diff --git a/utils/test/unittest/dinput_context_test.cpp b/utils/test/unittest/dinput_context_test.cpp index e994cbb1be65a10fe7a984d5e4d462afb9224023..7c541d691cf2385dda698fee863ac3b071fb1368 100644 --- a/utils/test/unittest/dinput_context_test.cpp +++ b/utils/test/unittest/dinput_context_test.cpp @@ -204,7 +204,7 @@ HWTEST_F(DInputContextTest, GetUUIDBySoftBus_001, testing::ext::TestSize.Level1) HWTEST_F(DInputContextTest, GetCurrentTime_001, testing::ext::TestSize.Level1) { - uint64_t ret = GetCurrentTime(); + uint64_t ret = GetCurrentTimeUs(); EXPECT_NE(0, ret); }