fix(Vehicle): remove initial connect outer timeouts causing slow-link failures (Stable_V5.1)

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();
     }

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<uint8_t> _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

src/FactSystem/ParameterManager.cc

@@ -260,7 +260,7 @@ void ParameterManager::_handleParamValue(int componentId, const QString &paramet
 
     _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 &paramName) const
@@ -1420,7 +1426,7 @@ QString ParameterManager::_remapParamNameToVersion(const QString &paramName) 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;
     }
 

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);

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<GimbalController*>(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;
     }
 }
 

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;

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);
 }
 

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()) {

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<WaitStateBase*>(sourceState())) {
             waitState->restartWait();

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

src/Vehicle/ComponentInformation/ComponentInformationManager.h

@@ -39,6 +39,7 @@ class ComponentInformationManager : public QGCStateMachine
 
 signals:
     void progressUpdate(float progress);
+    void requestAllComplete();
 
 private:
     void _createStates();

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) {