From b63fbf37ee70f7d0669e5267b5985fa2212e14e8 Mon Sep 17 00:00:00 2001 From: Don Gagne Date: Tue, 1 Sep 2026 10:17:49 -0700 Subject: [PATCH] fix(Vehicle): remove initial connect outer timeouts causing slow-link failures The fixed outer timeouts on each InitialConnectStateMachine state could fire on slow links (e.g. SiK radios) even though the underlying protocols (ParameterManager, PlanManager, ComponentInformationManager, StandardModes) handle their own timeouts/retries and always signal completion. Force-advancing on timeout left the vehicle half-initialized. ParameterManager gains a terminal initialParametersRequestFailed signal so the Parameters state can advance when the vehicle never answers PARAM_REQUEST_LIST. Also fixes GimbalController sending MAV_CMD_REQUEST_MESSAGE raw, which collided with RequestMessageCoordinator users in the command queue duplicate check and flakily failed the AVAILABLE_MODES fetch. Also improves timeout/failure logging visibility and sanitizes downloaded URL logging. --- src/Comms/MockLink/MockLink.cc | 11 +- src/Comms/MockLink/MockLink.h | 8 +- src/FactSystem/ParameterManager.cc | 18 ++- src/FactSystem/ParameterManager.h | 1 + src/Gimbal/GimbalController.cc | 34 ++++- src/Gimbal/GimbalController.h | 3 + src/Utilities/Network/QGCFileDownload.cc | 7 +- .../StateMachine/States/WaitStateBase.cc | 2 +- .../Transitions/RetryTransition.cc | 2 +- .../ComponentInformationManager.cc | 7 +- .../ComponentInformationManager.h | 1 + .../RequestMetaDataTypeStateMachine.cc | 4 +- src/Vehicle/InitialConnectStateMachine.cc | 85 ++++-------- src/Vehicle/InitialConnectStateMachine.h | 13 +- src/Vehicle/RequestMessageCoordinator.cc | 32 ++++- src/Vehicle/RequestMessageCoordinator.h | 9 ++ src/Vehicle/StandardModes.cc | 11 +- src/Vehicle/StandardModes.h | 3 +- src/Vehicle/Vehicle.cc | 6 + test/FactSystem/ParameterManagerTest.cc | 14 ++ test/FactSystem/ParameterManagerTest.h | 1 + .../BaseClasses/StateMachineTest.cc | 7 + .../BaseClasses/StateMachineTest.h | 3 + .../StateMachine/QGCStateMachineTest.cc | 1 + .../states/AsyncFunctionStateTest.cc | 1 + .../RetryableRequestMessageStateTest.cc | 6 + .../states/SkippableAsyncStateTest.cc | 1 + .../states/WaitForSignalStateTest.cc | 2 + .../StateMachine/states/WaitStateBaseTest.cc | 1 + .../transitions/RetryTransitionTest.cc | 6 + test/Vehicle/CMakeLists.txt | 3 + test/Vehicle/InitialConnectTest.cc | 131 +++++++++--------- test/Vehicle/InitialConnectTest.h | 7 +- test/Vehicle/StandardModesTest.cc | 23 +++ test/Vehicle/StandardModesTest.h | 14 ++ 35 files changed, 308 insertions(+), 170 deletions(-) create mode 100644 test/Vehicle/StandardModesTest.cc create mode 100644 test/Vehicle/StandardModesTest.h diff --git a/src/Comms/MockLink/MockLink.cc b/src/Comms/MockLink/MockLink.cc index 2b42240b7d55..8358c1a0060c 100644 --- a/src/Comms/MockLink/MockLink.cc +++ b/src/Comms/MockLink/MockLink.cc @@ -444,11 +444,6 @@ void MockLink::run1HzTasks() _sendHomePositionDelayCount--; } else { _sendHomePosition(); - // We piggy back on this delay to signal we have new standard modes available - if (_availableModesMonitorSeqNumber == 0) { - qCDebug(MockLinkLog) << "Bumping sequence number for available modes monitor to trigger requery of modes"; - _availableModesMonitorSeqNumber = 1; - } } } @@ -488,6 +483,11 @@ void MockLink::run10HzTasks() void MockLink::run500HzTasks() { + if (_mavlinkStarted && _connected && mavlinkChannelIsSet()) { + // Standard modes are served even on high-latency links since the request is still accepted there. + _availableModesWorker(); + } + if (linkConfiguration()->isHighLatency()) { return; } @@ -498,7 +498,6 @@ void MockLink::run500HzTasks() _paramRequestListWorker(); } _logDownloadWorker(); - _availableModesWorker(); _apmCompassCalWorker(); _apmAccelCalWorker(); } diff --git a/src/Comms/MockLink/MockLink.h b/src/Comms/MockLink/MockLink.h index a4a2c89bd4a8..a6fe1fb17d06 100644 --- a/src/Comms/MockLink/MockLink.h +++ b/src/Comms/MockLink/MockLink.h @@ -118,6 +118,10 @@ class MockLink : public LinkInterface } int receivedMissionRequestListCount(MAV_MISSION_TYPE type) const { return _missionItemHandler->requestListCount(type); } + /// Unit test support: bumps the AVAILABLE_MODES_MONITOR sequence number, which unlocks the + /// delayed flight mode and causes QGC to re-query standard modes. + void bumpAvailableModesMonitorSequence() { ++_availableModesMonitorSeqNumber; } + enum RequestMessageFailureMode_t { FailRequestMessageNone, FailRequestMessageCommandAcceptedMsgNotSent, @@ -422,7 +426,9 @@ private slots: /// - Main thread: _handleRequestMessageAvailableModes() checking/starting/stopping worker /// - Worker thread: _availableModesWorker() incrementing index every 2ms (500Hz) QMutex _availableModesWorkerMutex; - uint8_t _availableModesMonitorSeqNumber = 0; ///< Sequence number for the next available mode message to send + /// Sequence number sent in AVAILABLE_MODES_MONITOR. Written from the test (main) thread via + /// bumpAvailableModesMonitorSequence, read from the worker thread at 1Hz/500Hz. + std::atomic _availableModesMonitorSeqNumber = 0; QString _logDownloadFilename; ///< Filename for log download which is in progress bool _logsErased = false; ///< Set by LOG_ERASE, LOG_REQUEST_LIST reports no logs diff --git a/src/FactSystem/ParameterManager.cc b/src/FactSystem/ParameterManager.cc index 4ce6fb317b50..c66378220277 100644 --- a/src/FactSystem/ParameterManager.cc +++ b/src/FactSystem/ParameterManager.cc @@ -260,7 +260,7 @@ void ParameterManager::_handleParamValue(int componentId, const QString ¶met _checkInitialLoadComplete(); - qCDebug(ParameterManagerVerbose1Log) << _logVehiclePrefix(componentId) << "_parameterUpdate complete"; + qCDebug(ParameterManagerVerbose1Log) << _logVehiclePrefix(componentId) << "_handleParamValue complete"; } QString ParameterManager::_vehicleAndComponentString(int componentId) const @@ -840,7 +840,7 @@ bool ParameterManager::_fillIndexBatchQueue(bool waitingParamTimeout) for (const int componentId: _waitingReadParamIndexMap.keys()) { if (_waitingReadParamIndexMap[componentId].count()) { qCDebug(ParameterManagerLog) << _logVehiclePrefix(componentId) << "_waitingReadParamIndexMap count" << _waitingReadParamIndexMap[componentId].count(); - qCDebug(ParameterManagerVerbose1Log) << _logVehiclePrefix(componentId) << "_waitingReadParamIndexMap" << _waitingReadParamIndexMap[componentId]; + qCDebug(ParameterManagerVerbose1Log) << _logVehiclePrefix(componentId) << "_waitingReadParamIndexMap (index, retry count)" << _waitingReadParamIndexMap[componentId]; } for (const int paramIndex: _waitingReadParamIndexMap[componentId].keys()) { @@ -877,7 +877,7 @@ void ParameterManager::_waitingParamTimeout() return; } - qCDebug(ParameterManagerLog) << _logVehiclePrefix(-1) << "_waitingParamTimeout"; + qCDebug(ParameterManagerLog) << _logVehiclePrefix(-1) << "_waitingParamTimeout after" << _waitingParamTimeoutTimer.interval() << "ms"; // Now that we have timed out for possibly the first time we can activate the index batch queue _indexBatchQueueActive = true; @@ -1062,6 +1062,7 @@ void ParameterManager::_writeLocalParamCache(int vehicleId, int componentId) if (cacheFile.open(QIODevice::WriteOnly | QIODevice::Truncate)) { QDataStream ds(&cacheFile); ds << cacheMap; + qCDebug(ParameterManagerLog) << "Parameter cache written" << cacheFile.fileName() << "paramCount:" << cacheMap.count(); } else { qCWarning(ParameterManagerLog) << "Failed to open cache file for writing" << cacheFile.fileName(); } @@ -1089,7 +1090,7 @@ void ParameterManager::_tryCacheHashLoad(int vehicleId, int componentId, const Q CacheMapName2ParamTypeVal cacheMap; QFile cacheFile(parameterCacheFile(vehicleId, componentId)); if (!cacheFile.exists()) { - qCDebug(ParameterManagerLog) << "No parameter cache file"; + qCDebug(ParameterManagerLog) << "Parameter cache usage failed - No parameter cache file"; if (!_hashCheckDone) { _hashCheckDone = true; if (_cacheOnlyHashCheck) { @@ -1394,12 +1395,17 @@ void ParameterManager::_paramRequestListTimeout() if (!_disableAllRetries && (++_initialRequestRetryCount <= _maxInitialRequestListRetry)) { qCDebug(ParameterManagerLog) << _logVehiclePrefix(-1) << "Retrying initial parameter request list"; _startParameterDownload(MAV_COMP_ID_ALL); - } else if (!_vehicle->genericFirmware()) { + return; + } + + qCDebug(ParameterManagerLog) << _logVehiclePrefix(-1) << "Initial parameter request list retries exhausted, giving up"; + if (!_vehicle->genericFirmware()) { const QString errorMsg = tr("Vehicle %1 did not respond to request for parameters. " "This will cause %2 to be unable to display its full user interface.").arg(_vehicle->id()).arg(QCoreApplication::applicationName()); qCDebug(ParameterManagerLog) << errorMsg; QGC::showAppMessage(errorMsg); } + emit initialParametersRequestFailed(); } QString ParameterManager::_remapParamNameToVersion(const QString ¶mName) const @@ -1420,7 +1426,7 @@ QString ParameterManager::_remapParamNameToVersion(const QString ¶mName) con const FirmwarePlugin::remapParamNameMajorVersionMap_t &majorVersionRemap = _vehicle->firmwarePlugin()->paramNameRemapMajorVersionMap(); if (!majorVersionRemap.contains(majorVersion)) { // No mapping for this major version - qCDebug(ParameterManagerLog) << "_remapParamNameToVersion: no major version mapping"; + qCDebug(ParameterManagerVerbose1Log) << "_remapParamNameToVersion: no major version mapping"; return paramName; } diff --git a/src/FactSystem/ParameterManager.h b/src/FactSystem/ParameterManager.h index 2a3645f4c706..c42520723b7b 100644 --- a/src/FactSystem/ParameterManager.h +++ b/src/FactSystem/ParameterManager.h @@ -122,6 +122,7 @@ class ParameterManager : public QObject void missingParametersChanged(bool missingParameters); void loadProgressChanged(float value); void cacheCheckOnlyFailed(); + void initialParametersRequestFailed(); ///< Vehicle never responded to PARAM_REQUEST_LIST, all retries exhausted void pendingWritesChanged(bool pendingWrites); void parameterDownloadSkippedChanged(); void factAdded(int componentId, Fact *fact); diff --git a/src/Gimbal/GimbalController.cc b/src/Gimbal/GimbalController.cc index 6851f2741859..b61e16fc2cf3 100644 --- a/src/Gimbal/GimbalController.cc +++ b/src/Gimbal/GimbalController.cc @@ -271,11 +271,35 @@ void GimbalController::_requestGimbalInformation(uint8_t compid) { qCDebug(GimbalControllerLog) << "_requestGimbalInformation(" << compid << ")"; - if (_vehicle) { - _vehicle->sendMavCommand(compid, - MAV_CMD_REQUEST_MESSAGE, - false /* no error */, - MAVLINK_MSG_ID_GIMBAL_MANAGER_INFORMATION); + if (!_vehicle) { + return; + } + if (_pendingInformationRequestCompId != -1) { + qCDebug(GimbalControllerLog) << "_requestGimbalInformation: request already in flight for compid" << _pendingInformationRequestCompId; + return; + } + + // Must go through requestMessage rather than sending MAV_CMD_REQUEST_MESSAGE directly so + // that it serializes with other request-message users targeting the same component + // (a raw send collides with theirs in the command queue's duplicate-command check). + _pendingInformationRequestCompId = compid; + _vehicle->requestMessage(_requestMessageResultHandler, + this, + compid, + MAVLINK_MSG_ID_GIMBAL_MANAGER_INFORMATION); +} + +void GimbalController::_requestMessageResultHandler(void* resultHandlerData, MAV_RESULT result, VehicleTypes::RequestMessageResultHandlerFailureCode_t failureCode, const mavlink_message_t& message) +{ + Q_UNUSED(message); + + auto* controller = static_cast(resultHandlerData); + controller->_pendingInformationRequestCompId = -1; + + // Success is handled by the normal GIMBAL_MANAGER_INFORMATION message dispatch and + // failures are retried from _checkComplete, so just log here. + if (result != MAV_RESULT_ACCEPTED) { + qCDebug(GimbalControllerLog) << "GIMBAL_MANAGER_INFORMATION request failed - result:" << result << "failureCode:" << failureCode; } } diff --git a/src/Gimbal/GimbalController.h b/src/Gimbal/GimbalController.h index 7be53832dbe2..06e7c46fe3d4 100644 --- a/src/Gimbal/GimbalController.h +++ b/src/Gimbal/GimbalController.h @@ -5,6 +5,7 @@ #include "Gimbal.h" #include "MAVLinkMessageType.h" +#include "VehicleTypes.h" class QmlObjectListModel; class Vehicle; @@ -91,6 +92,7 @@ private slots: }; void _requestGimbalInformation(uint8_t compid); + static void _requestMessageResultHandler(void* resultHandlerData, MAV_RESULT result, VehicleTypes::RequestMessageResultHandlerFailureCode_t failureCode, const mavlink_message_t& message); void _handleHeartbeat(const mavlink_message_t &message); void _handleGimbalManagerInformation(const mavlink_message_t &message); void _handleGimbalManagerStatus(const mavlink_message_t &message); @@ -104,6 +106,7 @@ private slots: QTimer _rateSenderTimer; Vehicle *_vehicle = nullptr; Gimbal *_activeGimbal = nullptr; + int _pendingInformationRequestCompId = -1; ///< compid of in-flight GIMBAL_MANAGER_INFORMATION request, -1 if none struct PotentialGimbalManager { unsigned requestGimbalManagerInformationRetries = 6; diff --git a/src/Utilities/Network/QGCFileDownload.cc b/src/Utilities/Network/QGCFileDownload.cc index 0232ec9f83f2..e675c0af5afd 100644 --- a/src/Utilities/Network/QGCFileDownload.cc +++ b/src/Utilities/Network/QGCFileDownload.cc @@ -143,7 +143,9 @@ bool QGCFileDownload::start(const QString &remoteUrl, const QGCNetworkHelper::Re // Create request with configuration QNetworkRequest request = QGCNetworkHelper::createRequest(url, config); - qCDebug(QGCFileDownloadLog) << "Starting download:" << url.toString() << "to" << _localPath; + qCDebug(QGCFileDownloadLog) << "Starting download:" + << url.toDisplayString(QUrl::RemoveUserInfo | QUrl::RemoveQuery | QUrl::RemoveFragment) + << "to" << _localPath; // Start download _currentReply = _networkManager->get(request); @@ -346,7 +348,8 @@ void QGCFileDownload::_onDownloadError(QNetworkReply::NetworkError code) break; } - qCWarning(QGCFileDownloadLog) << "Download error:" << errorMsg; + qCWarning(QGCFileDownloadLog) << "Download error:" << errorMsg << "url:" + << _url.toDisplayString(QUrl::RemoveUserInfo | QUrl::RemoveQuery | QUrl::RemoveFragment); _setErrorString(errorMsg); } diff --git a/src/Utilities/StateMachine/States/WaitStateBase.cc b/src/Utilities/StateMachine/States/WaitStateBase.cc index 5840bfccaf55..431674263715 100644 --- a/src/Utilities/StateMachine/States/WaitStateBase.cc +++ b/src/Utilities/StateMachine/States/WaitStateBase.cc @@ -46,7 +46,7 @@ void WaitStateBase::_onTimeout() return; } - qCDebug(QGCStateMachineLog) << "Timeout" << stateName(); + qCWarning(QGCStateMachineLog) << "Timeout" << stateName() << "after" << _timeoutTimer.interval() << "ms"; // Record timeout for statistics if (machine()) { diff --git a/src/Utilities/StateMachine/Transitions/RetryTransition.cc b/src/Utilities/StateMachine/Transitions/RetryTransition.cc index 9c94098195d7..61386b69ccde 100644 --- a/src/Utilities/StateMachine/Transitions/RetryTransition.cc +++ b/src/Utilities/StateMachine/Transitions/RetryTransition.cc @@ -20,7 +20,7 @@ bool RetryTransition::eventTest(QEvent* event) if (_retryCount < _maxRetries) { _retryCount++; - qCDebug(RetryTransitionLog) << stateName << "timeout, retry" << _retryCount << "of" << _maxRetries; + qCWarning(RetryTransitionLog) << stateName << "timeout, retry" << _retryCount << "of" << _maxRetries; if (auto* waitState = qobject_cast(sourceState())) { waitState->restartWait(); diff --git a/src/Vehicle/ComponentInformation/ComponentInformationManager.cc b/src/Vehicle/ComponentInformation/ComponentInformationManager.cc index cd5a512d8832..45a647c329c9 100644 --- a/src/Vehicle/ComponentInformation/ComponentInformationManager.cc +++ b/src/Vehicle/ComponentInformation/ComponentInformationManager.cc @@ -179,10 +179,8 @@ void ComponentInformationManager::requestAllComponentInformation(RequestAllCompl _requestAllCompleteFn = requestAllCompletFn; _requestAllCompleteFnData = requestAllCompleteFnData; - // Guard against double-start: when InitialConnectStateMachine's CompInfo - // state times out, the retry callback re-invokes this method while the CIM - // state machine is still running. Only start if not already in progress; - // the updated callback pointers above are sufficient for the retry path. + // Guard against double-start: a request while already running just updates the + // callback pointers; the running machine still emits requestAllComplete at the end. if (!isRunning()) { start(); } @@ -242,6 +240,7 @@ void ComponentInformationManager::_signalComplete() _requestAllCompleteFn = nullptr; _requestAllCompleteFnData = nullptr; } + emit requestAllComplete(); } bool ComponentInformationManager::_isCompTypeSupported(COMP_METADATA_TYPE type) const diff --git a/src/Vehicle/ComponentInformation/ComponentInformationManager.h b/src/Vehicle/ComponentInformation/ComponentInformationManager.h index 538e790911d5..af245baa1830 100644 --- a/src/Vehicle/ComponentInformation/ComponentInformationManager.h +++ b/src/Vehicle/ComponentInformation/ComponentInformationManager.h @@ -39,6 +39,7 @@ class ComponentInformationManager : public QGCStateMachine signals: void progressUpdate(float progress); + void requestAllComplete(); private: void _createStates(); diff --git a/src/Vehicle/ComponentInformation/RequestMetaDataTypeStateMachine.cc b/src/Vehicle/ComponentInformation/RequestMetaDataTypeStateMachine.cc index 66073711fe8b..dcd47deb57cf 100644 --- a/src/Vehicle/ComponentInformation/RequestMetaDataTypeStateMachine.cc +++ b/src/Vehicle/ComponentInformation/RequestMetaDataTypeStateMachine.cc @@ -387,7 +387,7 @@ void RequestMetaDataTypeStateMachine::_requestTranslate() typeToString())) { disconnect(_compMgr->translation(), &ComponentInformationTranslation::downloadComplete, this, &RequestMetaDataTypeStateMachine::_downloadAndTranslationComplete); - qCDebug(RequestMetaDataTypeStateMachineLog) << "downloadAndTranslate() failed"; + qCDebug(RequestMetaDataTypeStateMachineLog) << typeToString() << ": translation skipped (English locale, locale unavailable, or download failure), using untranslated metadata"; _stateRequestTranslate->complete(); } } @@ -499,7 +499,7 @@ void RequestMetaDataTypeStateMachine::_requestFile(const QString& cacheFileTag, qCDebug(RequestMetaDataTypeStateMachineLog) << typeToString() << ": not found in cache, downloading"; } - qCDebug(RequestMetaDataTypeStateMachineLog) << "Downloading json" << uri; + qCDebug(RequestMetaDataTypeStateMachineLog) << typeToString() << ": downloading json" << uri; if (_uriIsMAVLinkFTP(uri)) { if (trackMetadataSource) { diff --git a/src/Vehicle/InitialConnectStateMachine.cc b/src/Vehicle/InitialConnectStateMachine.cc index 9a5d17b8482c..2d53176b54a2 100644 --- a/src/Vehicle/InitialConnectStateMachine.cc +++ b/src/Vehicle/InitialConnectStateMachine.cc @@ -29,7 +29,6 @@ InitialConnectStateMachine::InitialConnectStateMachine(Vehicle* vehicle, QObject _createStates(); _wireTransitions(); _wireProgressTracking(); - _wireTimeoutHandling(); setInitialState(_stateAutopilotVersion); } @@ -54,9 +53,8 @@ void InitialConnectStateMachine::_createStates() [this](Vehicle*, const mavlink_message_t& message) { _handleAutopilotVersionSuccess(message); }, - _maxRetries, - MAV_COMP_ID_AUTOPILOT1, - _timeoutAutopilotVersion + _autopilotVersionMaxRetries, + MAV_COMP_ID_AUTOPILOT1 ); _stateAutopilotVersion->setSkipPredicate([this]() { return _shouldSkipAutopilotVersionRequest(); @@ -66,22 +64,27 @@ void InitialConnectStateMachine::_createStates() }); // State 1: Request standard modes + // No timeout: download duration varies too much with link speed and mode count. + // The standard modes protocol handles all timeouts internally and always signals completion. _stateStandardModes = new AsyncFunctionState( QStringLiteral("RequestStandardModes"), this, - [this](AsyncFunctionState* state) { _requestStandardModes(state); }, - _timeoutStandardModes + [this](AsyncFunctionState* state) { _requestStandardModes(state); } ); // State 2: Request component information + // No timeout: ComponentInformationManager's nested state machines have per-state + // timeouts on every step and always signal completion. _stateCompInfo = new AsyncFunctionState( QStringLiteral("RequestCompInfo"), this, - [this](AsyncFunctionState* state) { _requestCompInfo(state); }, - _timeoutCompInfo + [this](AsyncFunctionState* state) { _requestCompInfo(state); } ); // State 3: Request parameters (skippable) + // No timeout: download duration varies too much with link speed and param count. + // ParameterManager handles all timeouts internally and always terminates via + // parametersReadyChanged or initialParametersRequestFailed. _stateParameters = new SkippableAsyncState( QStringLiteral("RequestParameters"), this, @@ -100,11 +103,11 @@ void InitialConnectStateMachine::_createStates() [this]() { qCDebug(InitialConnectStateMachineLog) << "Skipping parameter download" << _lastSkipReason; vehicle()->_parameterManager->setParameterDownloadSkipped(true); - }, - _timeoutParameters + } ); // State 4: Request mission (skippable) + // No timeout: PlanManager handles all timeouts/retries internally and always signals completion. _stateMission = new SkippableAsyncState( QStringLiteral("RequestMission"), this, @@ -112,11 +115,11 @@ void InitialConnectStateMachine::_createStates() [this](SkippableAsyncState* state) { _requestMission(state); }, [this]() { qCDebug(InitialConnectStateMachineLog) << "Skipping mission load" << _lastSkipReason; - }, - _timeoutMission + } ); // State 5: Request geofence (skippable) + // No timeout: PlanManager handles all timeouts/retries internally and always signals completion. _stateGeoFence = new SkippableAsyncState( QStringLiteral("RequestGeoFence"), this, @@ -133,11 +136,11 @@ void InitialConnectStateMachine::_createStates() [this](SkippableAsyncState* state) { _requestGeoFence(state); }, [this]() { qCDebug(InitialConnectStateMachineLog) << "Skipping geofence load" << _lastSkipReason; - }, - _timeoutGeoFence + } ); // State 6: Request rally points (skippable) + // No timeout: PlanManager handles all timeouts/retries internally and always signals completion. _stateRallyPoints = new SkippableAsyncState( QStringLiteral("RequestRallyPoints"), this, @@ -157,8 +160,7 @@ void InitialConnectStateMachine::_createStates() // Mark plan request complete when skipping vehicle()->_initialPlanRequestComplete = true; emit vehicle()->initialPlanRequestCompleteChanged(true); - }, - _timeoutRallyPoints + } ); // State 7: Signal completion @@ -226,34 +228,6 @@ void InitialConnectStateMachine::_onSubProgressUpdate(double progressValue) setSubProgress(static_cast(progressValue)); } -// ============================================================================ -// Timeout Handling -// ============================================================================ - -void InitialConnectStateMachine::_wireTimeoutHandling() -{ - // Note: _stateAutopilotVersion is RetryableRequestMessageState which handles its own retry - - // Use addRetryTransition builder for cleaner timeout handling - addRetryTransition(_stateStandardModes, &WaitStateBase::timedOut, _stateCompInfo, - [this]() { _requestStandardModes(_stateStandardModes); }, _maxRetries); - - addRetryTransition(_stateCompInfo, &WaitStateBase::timedOut, _stateParameters, - [this]() { _requestCompInfo(_stateCompInfo); }, _maxRetries); - - addRetryTransition(_stateParameters, &WaitStateBase::timedOut, _stateMission, - [this]() { _requestParameters(_stateParameters); }, _maxRetries); - - addRetryTransition(_stateMission, &WaitStateBase::timedOut, _stateGeoFence, - [this]() { _requestMission(_stateMission); }, _maxRetries); - - addRetryTransition(_stateGeoFence, &WaitStateBase::timedOut, _stateRallyPoints, - [this]() { _requestGeoFence(_stateGeoFence); }, _maxRetries); - - addRetryTransition(_stateRallyPoints, &WaitStateBase::timedOut, _stateComplete, - [this]() { _requestRallyPoints(_stateRallyPoints); }, _maxRetries); -} - // ============================================================================ // Skip Predicates // ============================================================================ @@ -406,15 +380,8 @@ void InitialConnectStateMachine::_requestCompInfo(AsyncFunctionState* state) this, &InitialConnectStateMachine::_onSubProgressUpdate); }); - vehicle()->_componentInformationManager->requestAllComponentInformation( - [](void* requestAllCompleteFnData) { - auto* self = static_cast(requestAllCompleteFnData); - if (self->_stateCompInfo) { - self->_stateCompInfo->complete(); - } - }, - this - ); + state->connectToCompletion(vehicle()->_componentInformationManager, &ComponentInformationManager::requestAllComplete); + vehicle()->_componentInformationManager->requestAllComponentInformation(nullptr, nullptr); } void InitialConnectStateMachine::_requestParameters(SkippableAsyncState* state) @@ -436,15 +403,23 @@ void InitialConnectStateMachine::_requestParameters(SkippableAsyncState* state) connect(vehicle()->_parameterManager, &ParameterManager::loadProgressChanged, this, &InitialConnectStateMachine::_onSubProgressUpdate, Qt::UniqueConnection); + // If the vehicle never answers PARAM_REQUEST_LIST, advance without parameters + const QMetaObject::Connection requestFailedConn = connect(vehicle()->_parameterManager, &ParameterManager::initialParametersRequestFailed, + state, [state]() { + qCDebug(InitialConnectStateMachineLog) << "Initial parameter request failed, advancing without parameters"; + state->complete(); + }); + state->connectToCompletion(vehicle()->_parameterManager, &ParameterManager::parametersReadyChanged, [this](bool parametersReady) { _onParametersReady(parametersReady); }); - // Ensure progress tracking is always cleaned up, including timeout/skip paths. - state->setOnExit([this, cacheFailedConn]() { + // Ensure progress tracking is always cleaned up, including failure/skip paths. + state->setOnExit([this, cacheFailedConn, requestFailedConn]() { disconnect(vehicle()->_parameterManager, &ParameterManager::loadProgressChanged, this, &InitialConnectStateMachine::_onSubProgressUpdate); + disconnect(requestFailedConn); if (cacheFailedConn) { disconnect(cacheFailedConn); } diff --git a/src/Vehicle/InitialConnectStateMachine.h b/src/Vehicle/InitialConnectStateMachine.h index ec4103d1e3dc..e69282325092 100644 --- a/src/Vehicle/InitialConnectStateMachine.h +++ b/src/Vehicle/InitialConnectStateMachine.h @@ -36,7 +36,6 @@ private slots: void _createStates(); void _wireTransitions(); void _wireProgressTracking(); - void _wireTimeoutHandling(); // State callbacks void _handleAutopilotVersionSuccess(const mavlink_message_t& message); @@ -70,15 +69,5 @@ private slots: RetryState* _stateComplete = nullptr; QGCFinalState* _stateFinal = nullptr; - // Timeout handling with retry - static constexpr int _maxRetries = 1; - - // Timeout values (ms) - static constexpr int _timeoutAutopilotVersion = 5000; - static constexpr int _timeoutStandardModes = 5000; - static constexpr int _timeoutCompInfo = 30000; - static constexpr int _timeoutParameters = 60000; - static constexpr int _timeoutMission = 30000; - static constexpr int _timeoutGeoFence = 15000; - static constexpr int _timeoutRallyPoints = 15000; + static constexpr int _autopilotVersionMaxRetries = 1; }; diff --git a/src/Vehicle/RequestMessageCoordinator.cc b/src/Vehicle/RequestMessageCoordinator.cc index c182eab4da7d..1ac592d8ae86 100644 --- a/src/Vehicle/RequestMessageCoordinator.cc +++ b/src/Vehicle/RequestMessageCoordinator.cc @@ -33,6 +33,35 @@ void RequestMessageCoordinator::stop() _queueMap.clear(); } +void RequestMessageCoordinator::_noOpResultHandler(void*, MAV_RESULT, RequestMessageResultHandlerFailureCode_t, const mavlink_message_t&) +{ +} + +void RequestMessageCoordinator::cancelRequests(void* resultHandlerData) +{ + // Repoint outstanding requests (active or queued) owned by resultHandlerData to the no-op + // handler rather than deleting them: an active request may still have a pending command in + // MavCommandQueue that references its RequestMessageInfo_t, so the info must stay alive and + // be cleaned up through the normal ack/timeout path — just without calling back into the + // now-dead context. + const auto repoint = [resultHandlerData](RequestMessageInfo_t* info) { + if (info->resultHandlerData == resultHandlerData) { + info->resultHandler = &_noOpResultHandler; + info->resultHandlerData = nullptr; + } + }; + for (auto& msgMap : _infoMap) { + for (RequestMessageInfo_t* info : msgMap) { + repoint(info); + } + } + for (auto& requestQueue : _queueMap) { + for (RequestMessageInfo_t* info : requestQueue) { + repoint(info); + } + } +} + bool RequestMessageCoordinator::_duplicate(int compId, int msgId) const { const mavlink_message_info_t* info = mavlink_get_message_info_by_id(msgId); @@ -185,8 +214,7 @@ void RequestMessageCoordinator::handleReceivedMessage(const mavlink_message_t& m void* timedOutHandlerData = nullptr; for (auto& compIdEntry : _infoMap) { for (auto info : compIdEntry) { - // Unit-test environments can have enough scheduling jitter that a 50ms - // response deadline causes false request-message timeouts. + // Shorter timeout during unit tests keeps failure-path tests fast. const int messageWaitTimeoutMs = QGC::runningUnitTests() ? 500 : 1000; if (info->messageWaitElapsedTimer.isValid() && info->messageWaitElapsedTimer.elapsed() > messageWaitTimeoutMs) { const mavlink_message_info_t* msgInfo = mavlink_get_message_info_by_id(info->msgId); diff --git a/src/Vehicle/RequestMessageCoordinator.h b/src/Vehicle/RequestMessageCoordinator.h index fa64766f0400..85460226a65c 100644 --- a/src/Vehicle/RequestMessageCoordinator.h +++ b/src/Vehicle/RequestMessageCoordinator.h @@ -38,6 +38,11 @@ class RequestMessageCoordinator : public QObject, public VehicleTypes /// Clear pending state without firing callbacks (used during vehicle shutdown). void stop(); + /// Neutralizes any outstanding requests owned by @a resultHandlerData so their result + /// callback is never invoked. Call this when the callback's context is being destroyed + /// while the vehicle (and this coordinator) keep running. + void cancelRequests(void* resultHandlerData); + static QString failureCodeToString(RequestMessageResultHandlerFailureCode_t failureCode); private: @@ -66,6 +71,10 @@ class RequestMessageCoordinator : public QObject, public VehicleTypes static void _cmdResultHandler(void* resultHandlerData, int compId, const mavlink_command_ack_t& ack, MavCmdResultFailureCode_t failureCode); + /// Result handler that outstanding requests are repointed to once their owning context is + /// destroyed. Intentionally does nothing. + static void _noOpResultHandler(void* resultHandlerData, MAV_RESULT commandResult, RequestMessageResultHandlerFailureCode_t failureCode, const mavlink_message_t& message); + Vehicle* _vehicle = nullptr; MavCommandQueue* _commandQueue = nullptr; diff --git a/src/Vehicle/StandardModes.cc b/src/Vehicle/StandardModes.cc index cd8e070e1602..7b0dbabaa04f 100644 --- a/src/Vehicle/StandardModes.cc +++ b/src/Vehicle/StandardModes.cc @@ -1,15 +1,16 @@ #include "StandardModes.h" #include "Vehicle.h" #include "QGCLoggingCategory.h" +#include "QGCMAVLink.h" QGC_LOGGING_CATEGORY(StandardModesLog, "Vehicle.StandardModes") static void requestMessageResultHandler(void *resultHandlerData, MAV_RESULT result, - [[maybe_unused]] Vehicle::RequestMessageResultHandlerFailureCode_t failureCode, + VehicleTypes::RequestMessageResultHandlerFailureCode_t failureCode, const mavlink_message_t &message) { StandardModes* standardModes = static_cast(resultHandlerData); - standardModes->gotMessage(result, message); + standardModes->gotMessage(result, failureCode, message); } StandardModes::StandardModes(QObject *parent, Vehicle *vehicle) @@ -17,7 +18,7 @@ StandardModes::StandardModes(QObject *parent, Vehicle *vehicle) { } -void StandardModes::gotMessage(MAV_RESULT result, const mavlink_message_t &message) +void StandardModes::gotMessage(MAV_RESULT result, VehicleTypes::RequestMessageResultHandlerFailureCode_t failureCode, const mavlink_message_t &message) { _requestActive = false; if (_wantReset) { @@ -88,7 +89,9 @@ void StandardModes::gotMessage(MAV_RESULT result, const mavlink_message_t &messa requestMode(availableModes.mode_index + 1); } } else { - qCDebug(StandardModesLog) << "Failed to retrieve available modes - REQUEST_MESSAGE:MAV_RESULT" << result; + // Environmental/normal outcome (vehicle doesn't support the protocol, comm loss, or a + // collapsed duplicate re-query), not a programming error, so log at debug level. + qCDebug(StandardModesLog) << "Failed to retrieve available modes - REQUEST_MESSAGE:MAV_RESULT" << QGCMAVLink::mavResultToString(result) << "failureCode:" << failureCode; emit requestCompleted(); } } diff --git a/src/Vehicle/StandardModes.h b/src/Vehicle/StandardModes.h index 7bb028c2da00..7419bae5d840 100644 --- a/src/Vehicle/StandardModes.h +++ b/src/Vehicle/StandardModes.h @@ -3,6 +3,7 @@ #include "FirmwarePlugin.h" #include "MAVLinkEnums.h" #include "MAVLinkMessageType.h" +#include "VehicleTypes.h" #include #include @@ -27,7 +28,7 @@ Q_OBJECT void availableModesMonitorReceived(uint8_t seq); - void gotMessage(MAV_RESULT result, const mavlink_message_t &message); + void gotMessage(MAV_RESULT result, VehicleTypes::RequestMessageResultHandlerFailureCode_t failureCode, const mavlink_message_t &message); signals: void modesUpdated(); diff --git a/src/Vehicle/Vehicle.cc b/src/Vehicle/Vehicle.cc index 4dbdf5514c34..f9ffe2ef28dc 100644 --- a/src/Vehicle/Vehicle.cc +++ b/src/Vehicle/Vehicle.cc @@ -449,6 +449,12 @@ void Vehicle::_deleteGimbalController() if (_gimbalController) { // Disconnect all signals to prevent any callbacks during or after deletion _gimbalController->disconnect(); + // The gimbal controller registers itself as the callback context for its GIMBAL_MANAGER_INFORMATION + // requestMessage calls. Cancel any still-outstanding request so the coordinator never calls back + // into the freed controller. + if (_reqMsgCoord) { + _reqMsgCoord->cancelRequests(_gimbalController); + } delete _gimbalController; _gimbalController = nullptr; } diff --git a/test/FactSystem/ParameterManagerTest.cc b/test/FactSystem/ParameterManagerTest.cc index 123aba4b89cf..3c37fd3913b1 100644 --- a/test/FactSystem/ParameterManagerTest.cc +++ b/test/FactSystem/ParameterManagerTest.cc @@ -14,6 +14,13 @@ #include "QGCMath.h" #include "Vehicle.h" +// Call from tests that deliberately let PARAM_SET / PARAM_REQUEST_READ waits time out. +void ParameterManagerTest::_ignoreParamResponseTimeouts() +{ + ignoreLogMessage("Utilities.QGCStateMachine", QtWarningMsg, + QRegularExpression("Timeout \".*WaitForParamResponseState\"")); +} + void ParameterManagerTest::cleanup() { // Some tests create MockLink directly (not via _connectMockLink), so we need special handling. @@ -103,6 +110,7 @@ void ParameterManagerTest::_requestListNoResponse() // param_read requests. void ParameterManagerTest::_requestListMissingParamFail() { + _ignoreParamResponseTimeouts(); QVERIFY2(!_mockLink, "MockLink already connected"); _mockLink = MockLink::startPX4MockLink(MockConfiguration::OptionNone, MockConfiguration::FailMissingParamOnAllRequests); MultiVehicleManager* vehicleMgr = MultiVehicleManager::instance(); @@ -132,6 +140,7 @@ void ParameterManagerTest::_requestListMissingParamFail() void ParameterManagerTest::_paramWriteNoAckRetry() { + _ignoreParamResponseTimeouts(); // BAT1_V_CHARGED requires a vehicle reboot, so writing it pops the reboot // app message (debounce is reset per-test by the framework) expectAppMessage(QRegularExpression("Reboot vehicle for changes to take effect")); @@ -142,6 +151,7 @@ void ParameterManagerTest::_paramWriteNoAckRetry() void ParameterManagerTest::_paramWriteNoAckPermanent() { + _ignoreParamResponseTimeouts(); // Expectations verify in FIFO order: reboot message first (fires at local // setRawValue), then the write-failed message (fires after retries exhaust) expectAppMessage(QRegularExpression("Reboot vehicle for changes to take effect")); @@ -166,6 +176,7 @@ void ParameterManagerTest::_paramWriteUInt16() void ParameterManagerTest::_paramReadFirstAttemptNoResponseRetry() { + _ignoreParamResponseTimeouts(); QVERIFY2(!_mockLink, "MockLink already connected"); _connectMockLink(); QVERIFY(_mockLink); @@ -190,6 +201,7 @@ void ParameterManagerTest::_paramReadFirstAttemptNoResponseRetry() void ParameterManagerTest::_paramReadNoResponse() { + _ignoreParamResponseTimeouts(); QVERIFY2(!_mockLink, "MockLink already connected"); _connectMockLink(); QVERIFY(_mockLink); @@ -558,6 +570,7 @@ void ParameterManagerTest::_bulkRefreshUnknownNameSkipped() // Round 0 fails (no response from MockLink), round 1 succeeds after failure mode is cleared. void ParameterManagerTest::_bulkRefreshRetrySucceeds() { + _ignoreParamResponseTimeouts(); _connectMockLink(); QVERIFY(_mockLink); QVERIFY(_vehicle); @@ -591,6 +604,7 @@ void ParameterManagerTest::_bulkRefreshRetrySucceeds() // All kMaxRetryRounds+1 rounds fail — BulkRefreshJob gives up without a success signal. void ParameterManagerTest::_bulkRefreshAllRetriesExhausted() { + _ignoreParamResponseTimeouts(); _connectMockLink(); QVERIFY(_mockLink); QVERIFY(_vehicle); diff --git a/test/FactSystem/ParameterManagerTest.h b/test/FactSystem/ParameterManagerTest.h index b3cdedd1b0b0..031eeff6227e 100644 --- a/test/FactSystem/ParameterManagerTest.h +++ b/test/FactSystem/ParameterManagerTest.h @@ -30,6 +30,7 @@ private slots: void _bulkRefreshAllRetriesExhausted(); private: + void _ignoreParamResponseTimeouts(); void _noFailureWorker(MockConfiguration::FailureMode_t failureMode); void _setParamWithFailureMode(MockLink::ParamSetFailureMode_t failureMode, bool expectSuccess, const QString ¶mName, MAV_AUTOPILOT autopilot); diff --git a/test/UnitTestFramework/BaseClasses/StateMachineTest.cc b/test/UnitTestFramework/BaseClasses/StateMachineTest.cc index 2788e8f5f7c5..6a73f8b44bb0 100644 --- a/test/UnitTestFramework/BaseClasses/StateMachineTest.cc +++ b/test/UnitTestFramework/BaseClasses/StateMachineTest.cc @@ -1,8 +1,15 @@ #include "StateMachineTest.h" +#include #include #include +void StateMachineTest::ignoreTimeoutWarnings() +{ + ignoreLogMessage("Utilities.QGCStateMachine", QtWarningMsg, QRegularExpression(QStringLiteral("^Timeout \""))); + ignoreLogMessage("Utilities.StateMachine.RetryTransition", QtWarningMsg, QRegularExpression(QStringLiteral("timeout, retry"))); +} + bool StateMachineTest::startAndWaitForFinished(QStateMachine* machine, int timeoutMs) { QSignalSpy finishedSpy(machine, &QStateMachine::finished); diff --git a/test/UnitTestFramework/BaseClasses/StateMachineTest.h b/test/UnitTestFramework/BaseClasses/StateMachineTest.h index 41b8f002239c..35196fc1e40f 100644 --- a/test/UnitTestFramework/BaseClasses/StateMachineTest.h +++ b/test/UnitTestFramework/BaseClasses/StateMachineTest.h @@ -50,6 +50,9 @@ class StateMachineTest : public UnitTest } protected: + /// Call from tests that deliberately drive a wait state to timeout/retry. + void ignoreTimeoutWarnings(); + /// Run a single state to completion using the default advance() signal. /// Creates a QFinalState, wires state's advance→final, sets initial state, starts, waits. /// @param state The state to run (must already be parented to @a machine) diff --git a/test/Utilities/StateMachine/QGCStateMachineTest.cc b/test/Utilities/StateMachine/QGCStateMachineTest.cc index fa49ce24d72f..2a9bd8da6ecd 100644 --- a/test/Utilities/StateMachine/QGCStateMachineTest.cc +++ b/test/Utilities/StateMachine/QGCStateMachineTest.cc @@ -222,6 +222,7 @@ void QGCStateMachineTest::_testTimeoutTransitionBuilder() void QGCStateMachineTest::_testRetryTransitionBuilder() { + ignoreTimeoutWarnings(); QGCStateMachine machine(QStringLiteral("RetryBuilderTest"), nullptr); int retryCount = 0; diff --git a/test/Utilities/StateMachine/states/AsyncFunctionStateTest.cc b/test/Utilities/StateMachine/states/AsyncFunctionStateTest.cc index b6c16cacab2a..2de631d9a3b7 100644 --- a/test/Utilities/StateMachine/states/AsyncFunctionStateTest.cc +++ b/test/Utilities/StateMachine/states/AsyncFunctionStateTest.cc @@ -32,6 +32,7 @@ void AsyncFunctionStateTest::_testAsyncFunctionState() void AsyncFunctionStateTest::_testAsyncFunctionStateTimeout() { + ignoreTimeoutWarnings(); QStateMachine machine; bool timeoutReached = false; const int timeoutMs = 100; diff --git a/test/Utilities/StateMachine/states/RetryableRequestMessageStateTest.cc b/test/Utilities/StateMachine/states/RetryableRequestMessageStateTest.cc index 77b4e14c8684..f042344c2009 100644 --- a/test/Utilities/StateMachine/states/RetryableRequestMessageStateTest.cc +++ b/test/Utilities/StateMachine/states/RetryableRequestMessageStateTest.cc @@ -52,6 +52,8 @@ void RetryableRequestMessageStateTest::_testRetryOnFailure() // FailRequestMessageCommandAcceptedMsgNotSent triggers duplicate-request warnings and retries exhausted. ignoreLogMessage("Vehicle.RequestMessageCoordinator", QtWarningMsg, QRegularExpression("failing exact duplicate compId:msgId")); + ignoreLogMessage("Utilities.QGCStateMachine", QtWarningMsg, + QRegularExpression("^Timeout \"TestMachine:RequestDebug\"")); ignoreLogMessage("Utilities.StateMachine.RetryableRequestMessageState", QtWarningMsg, QRegularExpression("Max retries exhausted")); _connectMockLinkNoInitialConnectSequence(); @@ -103,6 +105,8 @@ void RetryableRequestMessageStateTest::_testMaxRetriesExhausted() // FailRequestMessageCommandNoResponse triggers duplicate-request warnings and retries exhausted. ignoreLogMessage("Vehicle.RequestMessageCoordinator", QtWarningMsg, QRegularExpression("failing exact duplicate compId:msgId")); + ignoreLogMessage("Utilities.QGCStateMachine", QtWarningMsg, + QRegularExpression("^Timeout \"TestMachine:RequestDebug\"")); ignoreLogMessage("Utilities.StateMachine.RetryableRequestMessageState", QtWarningMsg, QRegularExpression("Max retries exhausted")); _connectMockLinkNoInitialConnectSequence(); @@ -149,6 +153,8 @@ void RetryableRequestMessageStateTest::_testFailOnMaxRetries() // Timeout + no-response mode causes MavCommandQueue and state machine to emit expected warnings. ignoreLogMessage("Utilities.StateMachine.RetryableRequestMessageState", QtWarningMsg, QRegularExpression("Max retries exhausted")); + ignoreLogMessage("Utilities.QGCStateMachine", QtWarningMsg, + QRegularExpression("^Timeout \"TestMachine:RequestDebug\"")); ignoreLogMessage("Vehicle.MavCommandQueue", QtWarningMsg, QRegularExpression("Giving up sending command after max retries:")); _connectMockLinkNoInitialConnectSequence(); diff --git a/test/Utilities/StateMachine/states/SkippableAsyncStateTest.cc b/test/Utilities/StateMachine/states/SkippableAsyncStateTest.cc index 037e1610a71f..46b1aa3c9e8b 100644 --- a/test/Utilities/StateMachine/states/SkippableAsyncStateTest.cc +++ b/test/Utilities/StateMachine/states/SkippableAsyncStateTest.cc @@ -87,6 +87,7 @@ void SkippableAsyncStateTest::_testSkippableAsyncStateSkip() void SkippableAsyncStateTest::_testSkippableAsyncStateTimeout() { + ignoreTimeoutWarnings(); QStateMachine machine; bool timeoutReached = false; const int timeoutMs = 100; diff --git a/test/Utilities/StateMachine/states/WaitForSignalStateTest.cc b/test/Utilities/StateMachine/states/WaitForSignalStateTest.cc index 9a977a8863ca..ac8de39b3a52 100644 --- a/test/Utilities/StateMachine/states/WaitForSignalStateTest.cc +++ b/test/Utilities/StateMachine/states/WaitForSignalStateTest.cc @@ -36,6 +36,7 @@ void WaitForSignalStateTest::_testWaitForSignalState() void WaitForSignalStateTest::_testWaitForSignalStateTimeout() { + ignoreTimeoutWarnings(); QStateMachine machine; QObject signalSource; bool timeoutReached = false; @@ -108,6 +109,7 @@ void WaitForSignalStateTest::_testCompletedSignal() void WaitForSignalStateTest::_testTimedOutSignal() { + ignoreTimeoutWarnings(); // Test that timedOut() is emitted alongside timeout() for wait states QStateMachine machine; QObject signalSource; diff --git a/test/Utilities/StateMachine/states/WaitStateBaseTest.cc b/test/Utilities/StateMachine/states/WaitStateBaseTest.cc index 2fddc6438931..389f241d1562 100644 --- a/test/Utilities/StateMachine/states/WaitStateBaseTest.cc +++ b/test/Utilities/StateMachine/states/WaitStateBaseTest.cc @@ -26,6 +26,7 @@ class TestWaitState : public WaitStateBase void WaitStateBaseTest::_testTimeoutEmission() { + ignoreTimeoutWarnings(); QStateMachine machine; const int timeoutMs = 50; diff --git a/test/Utilities/StateMachine/transitions/RetryTransitionTest.cc b/test/Utilities/StateMachine/transitions/RetryTransitionTest.cc index c1e1c9f86685..f609b5d69342 100644 --- a/test/Utilities/StateMachine/transitions/RetryTransitionTest.cc +++ b/test/Utilities/StateMachine/transitions/RetryTransitionTest.cc @@ -18,6 +18,7 @@ class RetryInspectableWaitState : public WaitStateBase void RetryTransitionTest::_testRetryActionCalled() { + ignoreTimeoutWarnings(); QStateMachine machine; int retryCount = 0; bool targetReached = false; @@ -58,6 +59,7 @@ void RetryTransitionTest::_testRetryActionCalled() void RetryTransitionTest::_testTransitionAfterMaxRetries() { + ignoreTimeoutWarnings(); QStateMachine machine; int retryCount = 0; bool targetReached = false; @@ -104,6 +106,7 @@ void RetryTransitionTest::_testTransitionAfterMaxRetries() void RetryTransitionTest::_testRetryCountResets() { + ignoreTimeoutWarnings(); // Test that retry count resets after transition is taken QStateMachine machine; int retryCount = 0; @@ -138,6 +141,7 @@ void RetryTransitionTest::_testRetryCountResets() void RetryTransitionTest::_testMultipleRetries() { + ignoreTimeoutWarnings(); QStateMachine machine; int retryCount = 0; bool targetReached = false; @@ -174,6 +178,7 @@ void RetryTransitionTest::_testMultipleRetries() void RetryTransitionTest::_testZeroRetries() { + ignoreTimeoutWarnings(); QStateMachine machine; int retryCount = 0; bool targetReached = false; @@ -210,6 +215,7 @@ void RetryTransitionTest::_testZeroRetries() void RetryTransitionTest::_testWaitRearmedBeforeRetryAction() { + ignoreTimeoutWarnings(); QStateMachine machine; bool waitWasRearmedBeforeRetryAction = false; diff --git a/test/Vehicle/CMakeLists.txt b/test/Vehicle/CMakeLists.txt index 2fa27d40d45a..e90c50acd228 100644 --- a/test/Vehicle/CMakeLists.txt +++ b/test/Vehicle/CMakeLists.txt @@ -39,6 +39,8 @@ target_sources(${CMAKE_PROJECT_NAME} SendMavCommandWithSignallingTest.h SetEstimatorOriginTest.cc SetEstimatorOriginTest.h + StandardModesTest.cc + StandardModesTest.h VehicleDistanceSensorFactGroupTest.cc VehicleDistanceSensorFactGroupTest.h VehicleLinkManagerTest.cc @@ -69,5 +71,6 @@ add_qgc_test(RequestMessageTest LABELS Integration Vehicle TIMEOUT ${QGC_TEST_TI add_qgc_test(SendMavCommandWithHandlerTest LABELS Integration Vehicle) add_qgc_test(SendMavCommandWithSignallingTest LABELS Integration Vehicle) add_qgc_test(SetEstimatorOriginTest LABELS Integration Vehicle) +add_qgc_test(StandardModesTest LABELS Integration Vehicle) add_qgc_test(VehicleDistanceSensorFactGroupTest LABELS Integration Vehicle) add_qgc_test(VehicleLinkManagerTest LABELS Integration Vehicle SERIAL) diff --git a/test/Vehicle/InitialConnectTest.cc b/test/Vehicle/InitialConnectTest.cc index cf45426127ce..8a5e0565cd3e 100644 --- a/test/Vehicle/InitialConnectTest.cc +++ b/test/Vehicle/InitialConnectTest.cc @@ -5,7 +5,6 @@ #include #include "GeoFenceManager.h" -#include "InitialConnectStateMachine.h" #include "LinkManager.h" #include "MAVLinkProtocol.h" #include "MultiVehicleManager.h" @@ -26,24 +25,6 @@ #include #include -void InitialConnectTest::init() -{ - VehicleTestManualConnect::init(); - // Many initial-connect tests exercise failure or timeout paths that produce these expected warnings. - ignoreLogMessage("ComponentInformation.RequestMetaDataTypeStateMachine", QtWarningMsg, - QRegularExpression("failed to load metadata")); - ignoreLogMessage("Utilities.StateMachine.RetryableRequestMessageState", QtWarningMsg, - QRegularExpression("Max retries exhausted")); - ignoreLogMessage("Utilities.StateMachine.RetryTransition", QtWarningMsg, - QRegularExpression("timeout after .* retries, advancing")); - // Timeout tests for Mission/GeoFence/Rally states cause transfer-failed showAppMessage logs. - ignoreLogMessage("API.QGCApplication.AppMessage", QtDebugMsg, - QRegularExpression("transfer failed")); - // StandardModes timeout exhausts MAV_CMD_REQUEST_MESSAGE retries in MavCommandQueue. - ignoreLogMessage("Vehicle.MavCommandQueue", QtWarningMsg, - QRegularExpression("Giving up sending command after max retries:")); -} - void InitialConnectTest::_performTestCases_data() { QTest::addColumn("failureMode"); @@ -74,6 +55,11 @@ void InitialConnectTest::_performTestCases() QFETCH(int, failureMode); QFETCH(QString, failureModeStr); TEST_DEBUG(QStringLiteral("Testing case failure mode: %1").arg(failureModeStr)); + if (failureMode != static_cast(MockConfiguration::FailNone)) { + // AUTOPILOT_VERSION failure rows exhaust request-message retries. + ignoreLogMessage("Utilities.StateMachine.RetryableRequestMessageState", QtWarningMsg, + QRegularExpression("Max retries exhausted")); + } _connectMockLink(MAV_AUTOPILOT_PX4, static_cast(failureMode)); _disconnectMockLink(); } @@ -148,6 +134,9 @@ void InitialConnectTest::_progressTracking() void InitialConnectTest::_highLatencySkipsPlanRequests() { + // High-latency links cannot fetch component metadata. + ignoreLogMessage("ComponentInformation.RequestMetaDataTypeStateMachine", QtWarningMsg, + QRegularExpression("failed to load metadata")); LinkManager::instance()->setConnectionsAllowed(); auto* mvm = MultiVehicleManager::instance(); @@ -182,6 +171,11 @@ void InitialConnectTest::_highLatencySkipsPlanRequests() void InitialConnectTest::_genericAutopilotVersionFailureSkipsUnsupportedPlanTypes() { + // AUTOPILOT_VERSION failure exhausts request-message retries; generic firmware has no metadata source. + ignoreLogMessage("Utilities.StateMachine.RetryableRequestMessageState", QtWarningMsg, + QRegularExpression("Max retries exhausted")); + ignoreLogMessage("ComponentInformation.RequestMetaDataTypeStateMachine", QtWarningMsg, + QRegularExpression("failed to load metadata")); _connectMockLink(MAV_AUTOPILOT_GENERIC, MockConfiguration::FailInitialConnectRequestMessageAutopilotVersionFailure); QVERIFY(_vehicle); @@ -215,8 +209,11 @@ void InitialConnectTest::_multipleReconnects() } } -void InitialConnectTest::_rallyTimeoutPathDoesNotLeakCompletionHandler() +void InitialConnectTest::_rallyFailurePathDoesNotLeakCompletionHandler() { + // Injected rally read failure pops a transfer-failed app message. + ignoreLogMessage("API.QGCApplication.AppMessage", QtDebugMsg, + QRegularExpression("Rally Point transfer failed")); LinkManager::instance()->setConnectionsAllowed(); auto* mvm = MultiVehicleManager::instance(); @@ -238,102 +235,109 @@ void InitialConnectTest::_rallyTimeoutPathDoesNotLeakCompletionHandler() auto* geoFenceManager = _vehicle->findChild(); auto* rallyPointManager = _vehicle->findChild(); - auto* initialConnectStateMachine = _vehicle->findChild(); QVERIFY(geoFenceManager); QVERIFY(rallyPointManager); - QVERIFY(initialConnectStateMachine); - connect(geoFenceManager, &GeoFenceManager::loadComplete, this, [this, initialConnectStateMachine]() { + connect(geoFenceManager, &GeoFenceManager::loadComplete, this, [this]() { _mockLink->setMissionItemFailureMode( MockLinkMissionItemHandler::FailReadRequestListNoResponse, MAV_MISSION_ACCEPTED); - initialConnectStateMachine->setTimeoutOverride(QStringLiteral("RequestRallyPoints"), 100); }); + // Rally read fails internally (PlanManager exhausts retries) but still signals + // loadComplete, so initial connect completes with the plan request marked complete. QSignalSpy initialConnectCompleteSpy{_vehicle, &Vehicle::initialConnectComplete}; QVERIFY(initialConnectCompleteSpy.wait(TestTimeout::longMs()) || _vehicle->isInitialConnectComplete()); - QVERIFY(!_vehicle->initialPlanRequestComplete()); + QVERIFY(_vehicle->initialPlanRequestComplete()); _mockLink->setMissionItemFailureMode(MockLinkMissionItemHandler::FailNone, MAV_MISSION_ACCEPTED); + // A leaked initial-connect completion handler would re-fire on this manual reload. QSignalSpy planCompleteSpy{_vehicle, &Vehicle::initialPlanRequestCompleteChanged}; QSignalSpy rallyLoadCompleteSpy{rallyPointManager, &RallyPointManager::loadComplete}; rallyPointManager->loadFromVehicle(); QVERIFY(rallyLoadCompleteSpy.wait(TestTimeout::longMs())); - QCOMPARE(planCompleteSpy.count(), 1); + QCOMPARE(planCompleteSpy.count(), 0); _disconnectMockLink(); } -void InitialConnectTest::_stateTimeoutFallsThrough_data() +void InitialConnectTest::_subsystemFailureFallsThrough_data() { QTest::addColumn>("blockedMessageIds"); QTest::addColumn("configFailureMode"); QTest::addColumn("blockMissionProtocolImmediately"); QTest::addColumn("blockMissionProtocolAfterMissionLoad"); - QTest::addColumn("timeoutOverrideStates"); QTest::addColumn("expectParametersReady"); - QTest::addColumn("expectPlanRequestComplete"); - - // Timeout matrix: - // +----------------+-------------------+------------------+---------+--------+ - // | State | Failure Injection | Timeout States | Params? | Plans? | - // +----------------+-------------------+------------------+---------+--------+ - // | StandardModes | Block AVAIL_MODES | StdModes | Yes | Yes | - // | CompInfo | Block COMP_META | CompInfo | Yes | Yes | - // | Parameters | No param response | Parameters | No | Yes | - // | Mission | Block mission req | Msn+Fence+Rally | Yes | No | - // | GeoFence | Block after msn | Fence+Rally | Yes | No | - // +----------------+-------------------+------------------+---------+--------+ + + // Each state's underlying subsystem must handle its own timeouts/retries and + // always signal completion, so initial connect finishes without outer timeouts. + // +----------------+-------------------+---------+ + // | State | Failure Injection | Params? | + // +----------------+-------------------+---------+ + // | StandardModes | Block AVAIL_MODES | Yes | + // | CompInfo | Block COMP_META | Yes | + // | Parameters | No param response | No | + // | Mission | Block mission req | Yes | + // | GeoFence | Block after msn | Yes | + // +----------------+-------------------+---------+ QTest::addRow("StandardModes") << QList{MAVLINK_MSG_ID_AVAILABLE_MODES} << static_cast(MockConfiguration::FailNone) << false << false - << QStringList{QStringLiteral("RequestStandardModes")} - << true << true; + << true; QTest::addRow("CompInfo") << QList{MAVLINK_MSG_ID_COMPONENT_METADATA} << static_cast(MockConfiguration::FailNone) << false << false - << QStringList{QStringLiteral("RequestCompInfo")} - << true << true; + << true; QTest::addRow("Parameters") << QList{} << static_cast(MockConfiguration::FailParamNoResponseToRequestList) << false << false - << QStringList{QStringLiteral("RequestParameters")} - << false << true; + << false; QTest::addRow("Mission") << QList{} << static_cast(MockConfiguration::FailNone) << true << false - << QStringList{QStringLiteral("RequestMission"), - QStringLiteral("RequestGeoFence"), - QStringLiteral("RequestRallyPoints")} - << true << false; + << true; QTest::addRow("GeoFence") << QList{} << static_cast(MockConfiguration::FailNone) << false << true - << QStringList{QStringLiteral("RequestGeoFence"), - QStringLiteral("RequestRallyPoints")} - << true << false; + << true; } -void InitialConnectTest::_stateTimeoutFallsThrough() +void InitialConnectTest::_subsystemFailureFallsThrough() { QFETCH(QList, blockedMessageIds); QFETCH(int, configFailureMode); QFETCH(bool, blockMissionProtocolImmediately); QFETCH(bool, blockMissionProtocolAfterMissionLoad); - QFETCH(QStringList, timeoutOverrideStates); QFETCH(bool, expectParametersReady); - QFETCH(bool, expectPlanRequestComplete); + + // Per-row expected noise from the injected subsystem failure. + if (blockedMessageIds.contains(MAVLINK_MSG_ID_AVAILABLE_MODES) || blockedMessageIds.contains(MAVLINK_MSG_ID_COMPONENT_METADATA)) { + ignoreLogMessage("Vehicle.MavCommandQueue", QtWarningMsg, + QRegularExpression("Giving up sending command after max retries:")); + } + if (blockedMessageIds.contains(MAVLINK_MSG_ID_COMPONENT_METADATA)) { + ignoreLogMessage("ComponentInformation.RequestMetaDataTypeStateMachine", QtWarningMsg, + QRegularExpression("failed to load metadata")); + } + if (configFailureMode == static_cast(MockConfiguration::FailParamNoResponseToRequestList)) { + ignoreLogMessage("API.QGCApplication.AppMessage", QtDebugMsg, + QRegularExpression("did not respond to request for parameters")); + } + if (blockMissionProtocolImmediately || blockMissionProtocolAfterMissionLoad) { + ignoreLogMessage("API.QGCApplication.AppMessage", QtDebugMsg, + QRegularExpression("transfer failed")); + } LinkManager::instance()->setConnectionsAllowed(); @@ -366,13 +370,6 @@ void InitialConnectTest::_stateTimeoutFallsThrough() _vehicle = mvm->activeVehicle(); QVERIFY(_vehicle); - auto* initialConnectStateMachine = _vehicle->findChild(); - QVERIFY(initialConnectStateMachine); - - for (const QString& stateName : timeoutOverrideStates) { - initialConnectStateMachine->setTimeoutOverride(stateName, 100); - } - if (blockMissionProtocolAfterMissionLoad) { auto* missionManager = _vehicle->findChild(); QVERIFY(missionManager); @@ -387,7 +384,7 @@ void InitialConnectTest::_stateTimeoutFallsThrough() QVERIFY(initialConnectCompleteSpy.wait(TestTimeout::longMs())); } QCOMPARE(_vehicle->parameterManager()->parametersReady(), expectParametersReady); - QCOMPARE(_vehicle->initialPlanRequestComplete(), expectPlanRequestComplete); + QVERIFY(_vehicle->initialPlanRequestComplete()); _disconnectMockLink(); } @@ -448,6 +445,12 @@ void InitialConnectTest::_stateRunMatrix() // Effective skip path in InitialConnectStateMachine is (isHighLatency || isLogReplay) const bool skipForLinkType = highLatency || logReplay; + if (skipForLinkType) { + // High-latency/log-replay links cannot fetch component metadata. + ignoreLogMessage("ComponentInformation.RequestMetaDataTypeStateMachine", QtWarningMsg, + QRegularExpression("failed to load metadata")); + } + // Enable noInitialDownloadWhenFlying setting for flying rows auto* noInitialDownloadWhenFlying = SettingsManager::instance()->mavlinkSettings()->noInitialDownloadWhenFlying(); const QVariant previousNoInitialDownloadWhenFlying = noInitialDownloadWhenFlying->rawValue(); diff --git a/test/Vehicle/InitialConnectTest.h b/test/Vehicle/InitialConnectTest.h index 8212a7f10f4c..1c2062a52920 100644 --- a/test/Vehicle/InitialConnectTest.h +++ b/test/Vehicle/InitialConnectTest.h @@ -7,7 +7,6 @@ class InitialConnectTest : public VehicleTestManualConnect Q_OBJECT private slots: - void init() override; void _performTestCases_data(); void _performTestCases(); void _boardVendorProductId(); @@ -15,9 +14,9 @@ private slots: void _highLatencySkipsPlanRequests(); void _genericAutopilotVersionFailureSkipsUnsupportedPlanTypes(); void _multipleReconnects(); - void _rallyTimeoutPathDoesNotLeakCompletionHandler(); - void _stateTimeoutFallsThrough_data(); - void _stateTimeoutFallsThrough(); + void _rallyFailurePathDoesNotLeakCompletionHandler(); + void _subsystemFailureFallsThrough_data(); + void _subsystemFailureFallsThrough(); void _stateRunMatrix_data(); void _stateRunMatrix(); }; diff --git a/test/Vehicle/StandardModesTest.cc b/test/Vehicle/StandardModesTest.cc new file mode 100644 index 000000000000..927fc483b8d1 --- /dev/null +++ b/test/Vehicle/StandardModesTest.cc @@ -0,0 +1,23 @@ +#include "StandardModesTest.h" + +#include "QGCMAVLink.h" +#include "Vehicle.h" + +void StandardModesTest::_monitorSequenceBumpTriggersRequery() +{ + // Initial connect has completed, so the initial AVAILABLE_MODES enumeration has settled. + // Assert on the re-query itself rather than on flightModes(), which a FirmwarePlugin can + // filter (e.g. custom builds hide modes that cannot be set by the user). + const int baselineRequests = _mockLink->receivedRequestMessageCount(MAVLINK_MSG_ID_AVAILABLE_MODES); + QVERIFY(baselineRequests > 0); + + // Bumping the sequence number changes the 1Hz AVAILABLE_MODES_MONITOR, which must cause + // StandardModes to re-query the mode list. + _mockLink->bumpAvailableModesMonitorSequence(); + + QTRY_VERIFY_WITH_TIMEOUT( + _mockLink->receivedRequestMessageCount(MAVLINK_MSG_ID_AVAILABLE_MODES) > baselineRequests, + TestTimeout::longMs()); +} + +UT_REGISTER_TEST(StandardModesTest, TestLabel::Integration, TestLabel::Vehicle) diff --git a/test/Vehicle/StandardModesTest.h b/test/Vehicle/StandardModesTest.h new file mode 100644 index 000000000000..3f1db0d1c630 --- /dev/null +++ b/test/Vehicle/StandardModesTest.h @@ -0,0 +1,14 @@ +#pragma once + +#include "BaseClasses/VehicleTest.h" + +class StandardModesTest : public VehicleTest +{ + Q_OBJECT + +public: + explicit StandardModesTest(QObject* parent = nullptr) : VehicleTest(parent) {} + +private slots: + void _monitorSequenceBumpTriggersRequery(); +};