diff --git a/include/depthai/xlink/XLinkConnection.hpp b/include/depthai/xlink/XLinkConnection.hpp index 484f8d2ec..73300a49c 100644 --- a/include/depthai/xlink/XLinkConnection.hpp +++ b/include/depthai/xlink/XLinkConnection.hpp @@ -153,6 +153,11 @@ class XLinkConnection { constexpr static std::chrono::milliseconds WAIT_FOR_BOOTUP_TIMEOUT{15000}; constexpr static std::chrono::milliseconds WAIT_FOR_CONNECT_TIMEOUT{5000}; constexpr static std::chrono::milliseconds POLLING_DELAY_TIME{10}; + + public: + std::string getMxId() const { + return deviceInfo.getMxId(); + } }; } // namespace dai diff --git a/include/depthai/xlink/XLinkStream.hpp b/include/depthai/xlink/XLinkStream.hpp index c6f3fd1f0..cc561f85d 100644 --- a/include/depthai/xlink/XLinkStream.hpp +++ b/include/depthai/xlink/XLinkStream.hpp @@ -77,6 +77,9 @@ class XLinkStream { [[deprecated]] void readRawRelease(); streamId_t getStreamId() const; + std::string getMxId() const { + return connection->getMxId(); + } }; struct XLinkError : public std::runtime_error { diff --git a/src/device/DeviceBase.cpp b/src/device/DeviceBase.cpp index b8bdc7b61..9ec037192 100644 --- a/src/device/DeviceBase.cpp +++ b/src/device/DeviceBase.cpp @@ -487,7 +487,7 @@ void DeviceBase::close() { void DeviceBase::closeImpl() { using namespace std::chrono; auto t1 = steady_clock::now(); - pimpl->logger.debug("Device about to be closed..."); + pimpl->logger.warn("Device mxid({}) about to be closed...", deviceInfo.getMxId()); // Close connection first; causes Xlink internal calls to unblock semaphore waits and // return error codes, which then allows queues to unblock @@ -513,7 +513,7 @@ void DeviceBase::closeImpl() { // At the end stop the monitor thread if(monitorThread.joinable()) monitorThread.join(); - pimpl->logger.debug("Device closed, {}", duration_cast(steady_clock::now() - t1).count()); + pimpl->logger.warn("Device mxid({}) closed, {}", deviceInfo.getMxId(), duration_cast(steady_clock::now() - t1).count()); } // This function is thread-unsafe. The idea of "isClosed" is ephemerial and @@ -608,7 +608,7 @@ void DeviceBase::init2(Config cfg, const dai::Path& pathToMvcmd, tl::optionallogger.debug("Found an actual device by given DeviceInfo: {}", deviceInfo.toString()); } else { deviceInfo.state = X_LINK_ANY_STATE; - pimpl->logger.debug("Searched, but no actual device found by given DeviceInfo"); + pimpl->logger.warn("Searched, but no actual device found by given DeviceInfo"); } } @@ -693,14 +693,14 @@ void DeviceBase::init2(Config cfg, const dai::Path& pathToMvcmd, tl::optionallogger.debug("Booting FW with Bootloader. Version {}, Time taken: {}", version.toString(), duration_cast(t2 - t1)); + pimpl->logger.warn("Booting FW with Bootloader. Version {}, Time taken: {}", version.toString(), duration_cast(t2 - t1)); // After that the state will be expectedBootState deviceInfo.state = expectedBootState; } else { // Boot into USB ROM BOOTLOADER bl.bootUsbRomBootloader(); - pimpl->logger.debug("Booting FW by jumping to USB ROM Bootloader first. Bootloader Version {}", version.toString()); + pimpl->logger.warn("Booting FW by jumping to USB ROM Bootloader first. Bootloader Version {}", version.toString()); // After that the state will be UNBOOTED deviceInfo.state = X_LINK_UNBOOTED; @@ -742,7 +742,7 @@ void DeviceBase::init2(Config cfg, const dai::Path& pathToMvcmd, tl::optionalread(); } catch(const std::exception& e) { // If any exception is thrown, log it and rethrow - implLogger.debug("RPC error: {}", e.what()); + implLogger.warn("RPC mxid({}) error: {}", rpcStream->getMxId(), e.what()); throw std::system_error(std::make_error_code(std::errc::io_error), "Device already closed or disconnected"); } }); diff --git a/src/xlink/XLinkConnection.cpp b/src/xlink/XLinkConnection.cpp index cb6de2a81..e830b6009 100644 --- a/src/xlink/XLinkConnection.cpp +++ b/src/xlink/XLinkConnection.cpp @@ -311,7 +311,7 @@ void XLinkConnection::close() { const auto ret = XLinkResetRemoteTimeout(deviceLinkId, static_cast(std::chrono::duration_cast(RESET_TIMEOUT).count())); if(ret != X_LINK_SUCCESS) { - logger::debug("XLinkResetRemoteTimeout({}) returned: {}", previousLinkId, XLinkErrorToStr(ret)); + logger::warn("XLinkResetRemoteTimeout({}) mxid({}) returned: {}", previousLinkId, deviceInfo.getMxId(), XLinkErrorToStr(ret)); } deviceLinkId = -1; @@ -331,12 +331,16 @@ void XLinkConnection::close() { } if(steady_clock::now() - t1 >= BOOTUP_SEARCH) { if(found) { - logger::debug("XLinkResetRemoteTimeout({}) post-reboot({}s) unusable state {}", + logger::warn("XLinkResetRemoteTimeout({}) mxid({}) post-reboot({}s) unusable state {}", previousLinkId, + deviceInfo.getMxId(), BOOTUP_SEARCH.count(), rebootingDeviceInfo.toString()); } else { - logger::debug("XLinkResetRemoteTimeout({}) post-reboot({}s) can't find device", previousLinkId, BOOTUP_SEARCH.count()); + logger::warn("XLinkResetRemoteTimeout({}) mxid({}) post-reboot({}s) can't find device", + previousLinkId, + deviceInfo.getMxId(), + BOOTUP_SEARCH.count()); } break; } @@ -344,7 +348,7 @@ void XLinkConnection::close() { }; } - logger::debug("XLinkResetRemoteTimeout({})", previousLinkId); + logger::debug("XLinkResetRemoteTimeout({}) mxid({})", previousLinkId, deviceInfo.getMxId()); } } diff --git a/tests/src/multiple_devices_test.cpp b/tests/src/multiple_devices_test.cpp index 0b35009b0..145fead1c 100644 --- a/tests/src/multiple_devices_test.cpp +++ b/tests/src/multiple_devices_test.cpp @@ -101,7 +101,10 @@ TEST_CASE("Multiple devices with 50 messages each") { } REQUIRE(finished); -} +} // the first device in vector cleanly destructs, but the 2nd and 3rd always post-reboot 5s can't find device + // curious as sometimes the found devices are in a different order but on destruct its always the 2nd and 3rd + // c++ std has no rule or guarantee for the order of vector element destruction -- fact that it differs in std lib implementations + // http://www7.open-std.org/JTC1/SC22/WG21/docs/papers/2017/p0752r0.md TEST_CASE("Multiple devices created and destroyed in parallel") { constexpr auto TEST_TIMEOUT = 30s;