Received ack for not-existing command: 511! Ignoring

This issue is driving me nuts! I am compiling mavsdk_server from the source using the git tag 1.4.8 on ARM64. The server compiles with no issues. I start up the server as follows:

mavsdk_server -p 50051 serial:///dev/ttyUSB0:57600

and it dumps the following to the console…

[10:41:31|Info ] MAVSDK version: v1.4.16 (mavsdk_impl.cpp:20)
[10:41:31|Info ] Waiting to discover system on serial:///dev/ttyUSB0:57600... (connection_initiator.h:20)
[10:41:31|Debug] New: System ID: 1 Comp ID: 0 (mavsdk_impl.cpp:496)
[10:41:31|Info ] System discovered (connection_initiator.h:63)
[10:41:31|Info ] Server started (grpc_server.cpp:53)
[10:41:31|Info ] Server set to listen on 0.0.0.0:50051 (grpc_server.cpp:54)
[10:41:31|Debug] Component Autopilot (1) added. (system_impl.cpp:377)
[10:41:31|Warn ] Vehicle type changed (new type: 13, old type: 0) (system_impl.cpp:225)
[10:41:31|Debug] New: System ID: 42 Comp ID: 190 (mavsdk_impl.cpp:496)
[10:41:31|Debug] Component Unsupported component (190) added. (system_impl.cpp:377)
[10:41:31|Debug] Discovered 1 component(s) (system_impl.cpp:578)
[10:41:32|Debug] Component Camera 1 (100) added. (system_impl.cpp:377)
[10:41:34|Debug] Component Unsupported component (250) added. (system_impl.cpp:377)
[10:41:39|Debug] New: System ID: 10 Comp ID: 250 (mavsdk_impl.cpp:496)
[10:41:39|Debug] Component Unsupported component (250) added. (system_impl.cpp:377)

I then launch my code and run the following:

self._drone = System(mavsdk_server_address="localhost", port=50051)
await self._drone.connect()

async for state in self._drone.core.connection_state():
     if state.is_connected:
          self._logger.info("Drone Connected!")
          break

try:
     await self._drone.telemetry.set_rate_home(5.0)
     self._logger.info(f"Set rate HOME telemetry messages to 5.0 ")
 except TelemetryError as ex:
     self._logger.info(f"Could not set rate of HOME messages.")
     self._logger.info(ex)
 try:
     await self._drone.telemetry.set_rate_gps_info(3.0)
     self._logger.info(f"Set rate GPS_INFO telemetry messages to 3.0 ")
 except TelemetryError as ex:
     self._logger.info(f"Could not set rate of GPS_INFO messages.")
     self._logger.info(ex)
...

The connection to the drone works as expected. However, when it hits the first SET_RATE_x command, the server will usually dump the following to the console:

[10:38:40|Warn ] Received ack for not-existing command: 511! Ignoring... (mavlink_command_sender.cpp:258)
[10:38:41|Warn ] sending again after 0.505082 s, retries to do: 3  (511). (mavlink_command_sender.cpp:287)
[10:38:41|Warn ] Received ack for not-existing command: 511! Ignoring... (mavlink_command_sender.cpp:258)
[10:38:41|Warn ] sending again after 1.00684 s, retries to do: 2  (511). (mavlink_command_sender.cpp:287)
[10:38:41|Warn ] Received ack for not-existing command: 511! Ignoring... (mavlink_command_sender.cpp:258)
[10:38:42|Warn ] sending again after 1.51356 s, retries to do: 1  (511). (mavlink_command_sender.cpp:287)
[10:38:42|Warn ] Received ack for not-existing command: 511! Ignoring... (mavlink_command_sender.cpp:258)
[10:38:42|Error] Retrying failed (511) (mavlink_command_sender.cpp:307)

What I see on the program side is the following:

22:38:38: [INFO] MAVLINK COMM : Could not set rate of HOME messages.
22:38:38: [INFO] MAVLINK COMM : TIMEOUT: 'Timeout'; origin: set_rate_home(); params: (5.0,)

The above repeats for each of the failed SET_RATE_x commands. The crazy thing is that if stop the code running and let everything sit for a while (duration seems random)… then rerun the above, it will connect, accept the SET_RATE_x commands and everything runs just fine. At that point, it seems to work, no matter how many times I restart the above, as long as I don’t power off the auto-pilot.

I don’t know enough about mavsdk_server yet to know where to start looking. I am running this on a Cube Orange with the latest Ardu firmware. I have seen 115 issues in the forum, but these all appear to have been fixed with the latest Ardu firmware.

I would have expected this to be a firmware issue or a command mapping issue, but why it works sometimes and not others is a mystery. Any help in pointing me where to look would be most appreciated.

UPDATE: I have tried changing things by providing a component or system id to mavsdk_server, but this does not seem to change anything.

Sometimes it also just works the first time. Is it possible it’s a serial cable issues? I am using a CP2102 USB to UART bridge cable connecting the companion computer to the TELEM2 port,

Do you have steps how I could reproduce this against ArduPilot SITL?

Hi @JulianOes, thanks for picking this up. So I did some more poking around and found more strange behavior. The good news is that I think it’s 100% hardware related.

I tried this same setup with Ardu SITL with a serial-over-TCP connection, and it works just fine. I tried about a thousand permutations of different steps (i.e. power the drone, clear python cache, restart terminal, power controller, etc.) but all produced the same random steps… sometimes it allows the set-rate messages and sometimes it won’t. The odd thing is that my code always connects to the mavsdk_server socket and mavsdk_server always connects to the drone.

Anyway, what I found that consistently works… is to power up the drone, controller, companion computer, autopilot, etc. and then plug in the USB to Serial cable to TELEM2. Once that is done, it works fine. I even found that I can leave the USB to serial cable connected… boot everything up… and as long as I unplug and plug the USB cable back into the companion computer, the set rate messages are accepted and things work fine.

So, it appears it must be something either with the USB port on the companion computer, the Cube TELEM2 port, or the actual USB-to-Serial cable itself. If you have any thoughts on that, it would be great.

I do also have another unrelated question. Does mavsdk_server have support for Ardu built in, or is it only going to work with parts of the mavlink specification that both Ardu and PX4 support? The reason I ask, is that some things like setting Ardu flight modes and reporting on current flight modes don’t work for Ardu but work fine for PX4.

If we were to help add Ardu capability, would you recommend expanding mavsdk_server or creating a new version of mavsdk_server that specifically supports Ardu?

It will depend. Some things should work, others not yet.

That’s one of the points that is not done yet. I was hoping to implement the common flight mode protocol which should not be ArduPilot/PX4 specific. Also see:
https://mavlink.io/en/messages/development.html#AVAILABLE_MODES
https://mavlink.io/en/messages/development.html#CURRENT_MODE
https://mavlink.io/en/messages/development.html#AVAILABLE_MODES_MONITOR

But I’m not opposed to having something intermediate until then.

I strongly suggest to avoid a fork. That’s because deployment of two versions would be a nightmare.
I think the differences can be at runtime: