Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

QGC 4.4.2 + AP4.5.7 Waypoint and Rally Point Read Write Issues #12076

Open
menschel opened this issue Nov 8, 2024 · 14 comments · May be fixed by #12184
Open

QGC 4.4.2 + AP4.5.7 Waypoint and Rally Point Read Write Issues #12076

menschel opened this issue Nov 8, 2024 · 14 comments · May be fixed by #12184
Assignees
@DonLakeFlyer
Labels
Report: Bug

Comments

@menschel
Copy link

menschel commented Nov 8, 2024

Expected Behavior

Waypoint (read from | write to) FC is possible.

Current Behavior

During initial connection GQC reads configuration from FC.
After parameters are finished, it tries to continue with Mission Items, i.e. Waypoints, Rally Points.
It fails with error popup
Mission read failed, maximum retries exceeded.
once for waypoints and another one for rally points.

Steps to Reproduce:

Please provide an unambiguous set of steps to reproduce the current behavior

  1. Connect an FC with Arduplane 4.5.7 to GQC.
  2. Wait for Configuration to load.
  3. Expect Error Popups half-way through.

System Information

When posting bug reports, include the following information

  • Operating System: Ubuntu Mate 24.04LTS
  • QGC Version: 4.4.2
  • QGC build: stable
  • Flight Controller: SpeedyBeeF405WingMini
  • Autopilot (with version): Arduplane 4.5.7

Detailed Description

FC is connected by UDP Port 14550.
That port is fed from a RM BANDIT MICRO module attached to a RM TX12MK2.
RC connection runs mavlink via ELRS feature.
https://www.expresslrs.org/software/mavlink/

Running APM-Planner_2-2.0.30-rc3-x86_64 instead of GQC shows that there is some index issue in the transmitted waypoints.
I think the format has changed somehow.

Log Files and Screenshots

[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanMasterController.cc:225 - "PlanMasterController::loadFromVehicle calling _missionController.loadFromVehicle"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:130 - ""loadFromVehicle T:Mission read sequence""
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:964 - "_setTransactionInProgress "T:Mission" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:146 - ""_requestList T:Mission _planType:_retryCount" 0 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:187 - ""Retrying T:Mission REQUEST_LIST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:146 - ""_requestList T:Mission _planType:_retryCount" 0 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:331 - ""_handleMissionCount T:Mission count:" 25"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 0 0"
[E] at :0 - "QString::arg: Argument missing: T:Mission, MISSION_ITEM"
[E] at :0 - "QString::arg: Argument missing: T:Mission, MISSION_COUNT"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:284 - ""Out of sequence ack T:Mission expected:received %2:%3""
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 0 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 0 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 1 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 1 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 1 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 1 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 1 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 1 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 6"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 1 6"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 0 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 1 22 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 2 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 1 22 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 1 22 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 1 22 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 1 22 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 2 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 1 22 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 1 22 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 2 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 3 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 3 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 3 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 3 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 3 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 3 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 6"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 3 6"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 2 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 3 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 4 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 4 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 3 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 3 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 3 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:431 - ""_handleMissionItem T:Mission seq:command:current:ardupilotHomePositionUpdate" 3 16 false false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 4 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 4 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 4 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 4 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Mission MISSION_REQUEST retry Count" 6"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Mission sequenceNumber:retry" 4 6"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:667 - ""Sending error - _planTypeString(T:Mission) errorCode(7) errorMsg(Mission read failed, maximum retries exceeded.)""
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:964 - "_setTransactionInProgress "T:Mission" 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:151 - "_newMissionItemsAvailableFromVehicle flyView:count true 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:174 - "loading from vehicle: count 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2088 - "_addMissionSettings"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2212 - "MissionController::_scanForAdditionalSettings count:scanIndex 1 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanMasterController.cc:238 - "PlanMasterController::_loadMissionComplete calling _geoFenceController.loadFromVehicle"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:130 - ""loadFromVehicle T:GeoFence read sequence""
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:964 - "_setTransactionInProgress "T:GeoFence" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:146 - ""_requestList T:GeoFence _planType:_retryCount" 1 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:151 - "_newMissionItemsAvailableFromVehicle flyView:count false 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:174 - "loading from vehicle: count 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2088 - "_addMissionSettings"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2212 - "MissionController::_scanForAdditionalSettings count:scanIndex 1 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionSettingsItem.cc:169 - "MissionSettingsItem::scanForMissionSettings count:scanIndex 1 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2371 - "setCurrentPlanViewSeqNum"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2371 - "setCurrentPlanViewSeqNum"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:151 - "_newMissionItemsAvailableFromVehicle flyView:count true 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:174 - "loading from vehicle: count 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2088 - "_addMissionSettings"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:2212 - "MissionController::_scanForAdditionalSettings count:scanIndex 1 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:1271 - "_recalcFlightPathSegments homePositionValid false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:1271 - "_recalcFlightPathSegments homePositionValid false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 3 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:1271 - "_recalcFlightPathSegments homePositionValid false"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:1537 - "_recalcMissionFlightStatus"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:1537 - "_recalcMissionFlightStatus"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/MissionController.cc:1537 - "_recalcMissionFlightStatus"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 3 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 4 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 4 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 4 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 4 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 4 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:187 - ""Retrying T:GeoFence REQUEST_LIST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:146 - ""_requestList T:GeoFence _planType:_retryCount" 1 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 4 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:187 - ""Retrying T:GeoFence REQUEST_LIST retry Count" 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:146 - ""_requestList T:GeoFence _planType:_retryCount" 1 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:410 - ""_handleMissionItem T:GeoFence dropping spurious item seq:command:missionType" 4 16 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:331 - ""_handleMissionCount T:GeoFence count:" 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:292 - "_readTransactionComplete read sequence complete"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:964 - "_setTransactionInProgress "T:GeoFence" 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanMasterController.cc:254 - "PlanMasterController::_loadGeoFenceComplete calling _rallyPointController.loadFromVehicle"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:130 - ""loadFromVehicle T:Rally read sequence""
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:964 - "_setTransactionInProgress "T:Rally" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:146 - ""_requestList T:Rally _planType:_retryCount" 2 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:323 - ""_handleMissionCount T:Rally Incorrect mission_type received expected:actual" 2 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:187 - ""Retrying T:Rally REQUEST_LIST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:146 - ""_requestList T:Rally _planType:_retryCount" 2 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:323 - ""_handleMissionCount T:Rally Incorrect mission_type received expected:actual" 2 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:331 - ""_handleMissionCount T:Rally count:" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Rally sequenceNumber:retry" 0 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Rally MISSION_REQUEST retry Count" 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Rally sequenceNumber:retry" 0 1"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Rally MISSION_REQUEST retry Count" 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Rally sequenceNumber:retry" 0 2"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Rally MISSION_REQUEST retry Count" 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Rally sequenceNumber:retry" 0 3"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Rally MISSION_REQUEST retry Count" 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Rally sequenceNumber:retry" 0 4"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Rally MISSION_REQUEST retry Count" 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Rally sequenceNumber:retry" 0 5"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:198 - ""Retrying T:Rally MISSION_REQUEST retry Count" 6"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:354 - ""_requestNextMissionItem T:Rally sequenceNumber:retry" 0 6"
[E] at :0 - "QString::arg: Argument missing: T:Rally, MISSION_ITEM"
[E] at :0 - "QString::arg: Argument missing: T:Rally, MISSION_COUNT"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:284 - ""Out of sequence ack T:Rally expected:received %2:%3""
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:667 - ""Sending error - _planTypeString(T:Rally) errorCode(7) errorMsg(Mission read failed, maximum retries exceeded.)""
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:964 - "_setTransactionInProgress "T:Rally" 0"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanMasterController.cc:267 - "PlanMasterController::_loadRallyPointsComplete"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanMasterController.cc:267 - "PlanMasterController::_loadRallyPointsComplete"
[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanMasterController.cc:267 - "PlanMasterController::_loadRallyPointsComplete"`
``
@DonLakeFlyer DonLakeFlyer self-assigned this Nov 15, 2024
@DonLakeFlyer DonLakeFlyer mentioned this issue Nov 15, 2024
Merged
@DonLakeFlyer
Copy link
Contributor

This looks like a firmware side protocol screw up. That said the full PlanManager lof isn't quite right. I just fixed a bug in there to get better logging. It was just merged. A new daily build with that fix should be available in about an hour. Can you repro this on daily and get a new PlanManager log from that?

@menschel
Copy link
Author

Sure, I'll wait for tomorrow and test with whatever Binary is linked here for linux.
https://docs.qgroundcontrol.com/master/en/qgc-user-guide/releases/daily_builds.html

Thanks for looking into the issue.

@menschel
Copy link
Author

I tested daily build and I can relate the issue to the Mavlink via ELRS feature.

When I connect the FC via Serial / USB everything works.

I'm currently struggling to actually log something because the console log does not show anything that I presumably selected for logging.

@menschel
Copy link
Author

Sorry, can't get any logging working with daily build, even --logging:full does not display anything that I selected for logging. All I get are some tile warnings from terrain-ce.suite.auterion.com

I'm running the daily of this commit
1b8f503

But I'll try one last thing here, not going through port 14550 but through a serial attached to the elrs module's usb port.

@menschel
Copy link
Author

Same effect through the elrs modules usb port, but it was much much faster until it threw the error message.

Again absolutely no logging even to command line except for the tile warnings.

@DonLakeFlyer
Copy link
Contributor

You can see what the problem is here in the logs:

[D] at ../../qgroundcontrol/qgroundcontrol/src/MissionManager/PlanManager.cc:463 - ""_handleMissionItem T:Mission mission item received item index which was not requested, disregrarding:" 0"

The firmware is returning the wrong mission item. It looks like the protocol is completely out of whack. Almost seems like the Vehicle->GCS traffic direction is being sent more than once. Same thing indicated by AMP Planner not working. This isn't a QGC thing as far as I can tell. It's either a firmware problem or a downlink (vehicle->GCS) setup problem.

@menschel
Copy link
Author

Agreed,

I believe it has something to do with being a stubborn sender.
https://www.expresslrs.org/software/mavlink/#stubborn-sender

Closing the issue therefore. I'll try to achieve some logging and attach it here for reference.

@menschel
Copy link
Author

I can further confirm, that the issue is only present with 900Mhz Mavlink via ELRS feature.
I tried the same thing on 2G4 with an arducopter testbench setup and the internal ELRS module of the RM TX12MK2.

It must be some issue on the 900Mhz RF Link.

@menschel
Copy link
Author

I have another indicator that it's related to ELRS. The same test bench setup with mLRS on Seeed WIO-E5 modules works without any issues, also 900Mhz RF Link. I will open an Issue there.

@menschel menschel mentioned this issue Nov 21, 2024
Closed
@menschel
Copy link
Author

@DonLakeFlyer Am I correct in the assumption that
_retryTimeoutMilliseconds = 250 can be increased for testing?
I believe this timeout is part of the issue on the slower 900Mhz link while it is sufficient on the 2G4 link.
I'll try to build it locally according to guide.

@DonLakeFlyer
Copy link
Contributor

DonLakeFlyer commented Dec 5, 2024 •
edited
Loading

Sorry lost track of this. Yeah that seems short. Try changing it to 1500 to see what happens. If you don't want to setup a whole build environment just submit a pull request with the change marked as Draft and then use the built artifact to test with.

@menschel
Copy link
Author

menschel commented Dec 9, 2024

Setting _retryTimeoutMilliseconds = 1500 has solved the initial issue at hand. I'm now searching for the corresponding timeout while writing fences and rally points.

I'll reopen this issue and eventually push PR afterwards.

BTW: Good writeup on the building instructions, I was struggling with distribution based qt packages for a week until I finally gave in to using the online installer and create an account.

@menschel menschel reopened this Dec 9, 2024
@DonLakeFlyer
Copy link
Contributor

I'm now searching for the corresponding timeout while writing fences and rally points.

If I remember correctly PlanManager is the base class for all of those isn't it?

@menschel menschel linked a pull request Dec 9, 2024 that will close this issue
Draft
3 tasks
@menschel
Copy link
Author

menschel commented Dec 9, 2024

Aye, everything was solved by tweaking the timeouts. I pushed PR. Thanks for bearing with me ^^;

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@DonLakeFlyer DonLakeFlyer

Labels
Report: Bug
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

PlanManager: Increase Timeouts for Mission Transfer menschel/qgroundcontrol
2 participants
@DonLakeFlyer @menschel