iNavFlight / inav

INAV: Navigation-enabled flight control software
https://inavflight.github.io
GNU General Public License v3.0
3.12k stars 1.47k forks source link

No GPS fix although fixed after soft reboot #5370

Closed FabianSchwartau closed 4 years ago

FabianSchwartau commented 4 years ago

Current Behavior

Drone is up and running and has a GPS fix and is ready to arm. After a soft restart it clains that it cannot arm because of missing GPS fix, although it has a fix.

Steps to Reproduce

  1. Use a drone with UBlox GPS module in UBX mode
  2. Turn on drone, wait for GPS fix and make sure drone is arm-able
  3. Soft reboot the drone using the stick menu or the configurator ("Save & Reboot")
  4. Wait for inav to reboot
  5. Inav now claims that it cannot arm, because it has no GPS fix
  6. Look at the # Sats, which is saying something between 10 and 20 in my case
  7. The value of the number of sats is also changing, so there is clearly data coming in and a fix available. But inav does not detect it.

Expected behavior

Indication of GPS fix when GPS is fixed.

Suggested solution(s)

I have no idea - if no one has a good idea, I will look into this further. Can someone point me to the interesting part (file) of the code where the decision if GPS is fixed is made?

Additional context

This only happens when in UBX mode. In NMEA mode it works. I guess inav is trying to switch the GPS into UBX mode - but it is already in UBX mode as it was not reset during restart. Maybe Inav waits for a confirmation of the mode switch but will never receive it as the GPS does not recognize the NMEA message. When I hard restart the drone, everything works just fine, always. Multiple soft restarts do not help either. I have also seen this problem on different GPS modules (NEO-6M and NEO-M8N) and for the NEO-6M also on two different drones. IMG_20200201_181631 IMG_20200201_181622


stronnag commented 4 years ago

I can't say that I've ever seen this problem on any version of iNav, from pre-1.0 to dev latest. Just tested it again with dev latest. Indoors, so 5 -6 sats and questionable HDOP. After soft reboot, as soon as it gets to 6 sats / acceptable epv/eph, arming is available.

Here's a mwp log extract:

2020-02-01T17:47:37+0000 Arming flags: Ready to Arm (0000), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T17:47:53+0000 Reboot scheduled
2020-02-01T17:48:03+0000 Arming flags: Navigation unsafe, • Fix quality, • 4 satellites (0800), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T17:48:31+0000 Arming flags: Ready to Arm (0000), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T17:48:39+0000  Reboot scheduled
2020-02-01T18:00:03+0000 Arming flags: Ready to Arm (0000), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T18:00:15+0000 Arming flags: Calibrating (0200), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T18:00:17+0000 Arming flags: Ready to Arm (0000), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T18:00:23+0000 Reboot scheduled
2020-02-01T18:00:33+0000 Arming flags: Navigation unsafe, • Nav mode engaged (0800), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T18:00:42+0000 Arming flags: Ready to Arm (0000), load 3% MSP_CMDS_INAV_STATUS
2020-02-01T18:00:47+0000 Reboot scheduled
2020-02-01T18:01:04+0000 Arming flags: Ready to Arm (0000), load 3% MSP_CMDS_INAV_STATUS

As an MSP consumer (compared to the OSD that has full access to the FC), mwp guesses that it's because a nav mode is engaged (18:00:33); it has no other supporting data (and parsing mode masks is a PIA), really it should say "Reason unknown" --- let me fix that. However, as soon as the FC decides navigation is safe, we're in an armable state (18:00:42)

post scriptum: mwp would now clarify (18:00:33) as:

2020-02-01T18:00:33+0000 Arming flags: Navigation unsafe, • Reason unknown; is a nav mode engaged? (0800), load 3% MSP_CMDS_INAV_STATUS

to clarify that it's not clear (to mwp) as to why navigation is unsafe

FabianSchwartau commented 4 years ago

OK, I tried to reproduce the output you got from mwp. My mwp disconnects when I do a soft restart, but the interesting thing is that after the soft restart it shows me this: 2020-02-02T11:25:25+0100 Arming flags: Navigation unsafe, • Fix quality, • 0 satellites (0800), load 9% MSP_CMDS_INAV_STATUS So it is telling me that there are 0 satellites in few, but the OSD says that there are 11 sats.

stronnag commented 4 years ago

Perhaps an OSD refresh issue ?

FabianSchwartau commented 4 years ago

I don't think so. Why would it update the number of sats? Like the number is changing. And why would there be no lock when it was seconds before. Waiting for minutes does not make inav detect a lock.

stronnag commented 4 years ago

I was thinking more like the OSD wasn't updating (to zero) and the number shown was that prior to reboot. Why your GPS doesn't reacquire a fix is a mystery.

FabianSchwartau commented 4 years ago

Why do you think my GPS is not reacquiring a fix? Where does the number of sats in the OSD would come from, if not from the GPS?

FabianSchwartau commented 4 years ago

One more thing: I just noticed, when the GPS is shown not locked after soft restart, the GPS tab in inav configurator shows that 3 messages have been transmitted and there was 1 error. I took a look at the initialization code of ubx and it is structured like this:

configureMSG(***, ***, ***);
ptWait(_ack_state == UBX_ACK_GOT_ACK);

So I guess that the initialization code gets a NACK or some other error and never finishes. For some reason the number of sats is updated anyway.

stronnag commented 4 years ago

Why do you think my GPS is not reacquiring a fix?

Because mwp says so, which it gets from MSP_RAW_GPS.

FabianSchwartau commented 4 years ago

And that there is a bug in inav that causes to not receive the data properly is impossible?

FabianSchwartau commented 4 years ago

And another thing. I just wired an USB/Serial converter to the GPS serial lines and captured this message while inav was claiming it has no fix:

b5 62 Start 01 03: Class/ID -> UBX-NAV-STATUS 10 00: Payload length -> 16 bytes 90 2b 4b 03: iTOW 03: gpsFix -> 3D dd: flags 00: fixStat 08 ca a4 00: flags2 00 ba e1 00: ttff 00: msss 0e 75: checksum

So it got a 3D fix but inav does not detect it.

stronnag commented 4 years ago

And that there is a bug in inav that causes to not receive the data properly is impossible?

Not impossible, but not apparent on multiple aircraft / FC / GPS here. Recently tested on MATEKF405 and WINGFC.

FabianSchwartau commented 4 years ago

Is there some sort of printf-debugging mechanism in inav?

stronnag commented 4 years ago

Sure is. See ./src/main/common/log.h for usage. I can never remember how this works when I need it. Time to document it!

FabianSchwartau commented 4 years ago

Can you (or someome else) remember how to extract the log data from an MSP port? Neither INAV Configurator nor mwp report anything. I set the VCP/MSP to share debugging: serial 20 +15 I set log level to debug: set log_level DEBUG I enabled system topic: set log_topics = 1 Anything else to do?

stronnag commented 4 years ago

I'm writing the doc now. For the impatient.

# typically MSP (1) + 32768
serial 20 32769 115200 115200 0 115200
set log_level = DEBUG
set log_topics = 4294967295

will catch pretty much everything

In code:

LOG_D(DEBUG,"This is a log %s, value %d", "message", 42);

It helps to have a serial console / logger that understands the MSP log frame, examples include:

FabianSchwartau commented 4 years ago

OK, I have not tracked down the issue, but I found a solution. You have to set the serial baud rate to a higher value than 9600. I thought my ublox works at 9600 out of the box and have not seen any information that you can set the baudrate to whatever you want and he will configure the module on each start. Nevertheless, there seems to be a problem when the module is set to 9600. My guess is that this is a timing issue. I found out that the gpsConfigure thread in gps_ublox.c fails to configure the module and is restarted after a short timeout. If the module is already started (or does a warm start) it is probably sending quite a lot of data as it already has a fix right at startup. This causes the answers to take a bit of time and the timeout is triggered randomly and the gpsConfigure thread restarts. I watched that the thread was able to send an arbitrary number of commands (1 to 6) before being reset. There might be three possible solutions to this. Tell me what you want. 1) Ignore this issue as it is probably not a big deal - but then I would expect somewhere to be a big red text telling you about this issue. 2) There is a reset command for the ublox. It could be possible to trigger that as the first action so the module looses the fix and will not send so much data. 3) Increase the timeout.

If you do not decide for variant number one, I can invest this a bit further.

stronnag commented 4 years ago

We addressed this a while ago, #3995 was merged in 2018. Defaults often have some reason behind them.

stronnag commented 4 years ago

Ublox at 10HZ sends > 1000 bytes/sec, so 9600 baud is in serial over-run land.

$ ublox-cli  -n   -d /dev/ttyACM0@115200
...
^C
2020-02-03T18:17:49+0000 29s, rx 29256b, tx 0b, (1012b/s, 0b/s)
FabianSchwartau commented 4 years ago

So I guess there is no interest in finding a solution for 9600 baud? Edit: Mine is running only at 5 Hz. So that should be enough for 9600. Can this be changed? My module supports 10 Hz.

stronnag commented 4 years ago

Edit: Mine is running only at 5 Hz. So that should be enough for 9600. Can this be changed? My module supports 10 Hz.

set gps_provider = UBLOX7
FabianSchwartau commented 4 years ago

OK, that works... Why is it called UBLOX7? I have an 8 and did not used it because it is not a 7. Internally the constant seems to be GPS_UBLOX7PLUS which makes much more sense to me.

stronnag commented 4 years ago

OK, that works... Why is it called UBLOX7? I have an 8 and did not used it because it is not a 7. Internally the constant seems to be GPS_UBLOX7PLUS which makes much more sense to me.

For hysterical reasons, once upon a time (c. 2015) we had UBLOX 6, which only supported 5Hz. UBLOX7 was the first to support 10Hz, 2016 probably. At the time we had a lot of discussion as to whether 10HZ would make your UAV explode. Fortunately, it didn't.