stronnag / mwptools

ground station, mission planner and tools for inav and multiwii-nav
http://stronnag.github.io/mwptools/
GNU General Public License v3.0
190 stars 35 forks source link

Unable to opens some logs #23

Closed giacomo892 closed 7 years ago

giacomo892 commented 7 years ago

I can play them with INAV blackbox explorer but with mwp (latest build for "ancient" ubuntu) no.

It says no log in the files.

LOG00352.TXT LOG00353.TXT

Can you gently take a look on what it is going on?

thanks

stronnag commented 7 years ago

Running blackbox_decode errors with

$ blackbox_decode ~/dl/LOG00352.TXT 
Decoding log '/home/jrh/dl/LOG00352.TXT' to '/home/jrh/dl/LOG00352.01.csv'...
Attempted to base prediction on GPS home position without GPS home frame definition

If you think this is wrong, please take it up with the blackbox_decode maintainer, mwp is defenceless if the definitive blackbox tool can't read the log.

stronnag commented 7 years ago

Same with the next file. Really not a mwp problem ....

stronnag commented 7 years ago

Current tool set

$ cd Projects/blackbox-tools/
$ git pull
Already up-to-date.
stronnag commented 7 years ago

OTOH, I have no problem with F1 and blackbox e.g. https://www.rcgroups.com/forums/showpost.php?p=37608816&postcount=14104

So I have zero idea what is the problem here. How old is your logger firmware?

stronnag commented 7 years ago

Please reopen if you really think this is a mwp issue. Maybe @digitalentity knows what the blackbox_decode error means.

stronnag commented 7 years ago

Even in the inav bb explorer, I see strangeness like (undefined) in the attached image. Not sure all is well with either your bbox logger or, dare I say it, the custom FC.

screenshot-20170527185729-879x47

stronnag commented 7 years ago

OTOH, we should give the poor user a clue about such failures. 342319deac865ab92e0731bb04e532e202ca9097 screenshot from 2017-05-27 19-30-57

(not that it is wonderfully informative in this case, alas)

stronnag commented 7 years ago

better UX: image Thanks for the inspiration.

stronnag commented 7 years ago

And if you're still convinced that this could not possibly, in any conceivable way be hardware related, perhaps consider raising an iNav issue that iNav creates logs with undefined values. Not withstanding that other F1s doesn't seem to behave like that.

giacomo892 commented 7 years ago

Hi! Thanks for your replies. Glad to be inspirative 💃

Anyway.

I'm running openlog light latest firmware with some stripped down code (digitalWrite removed in favour of direct registers access) but i'm not running the "cleanflight edition" of the openlog like you can see:

OpenLog_Minimal.zip

Beside that until yesterday I had no issues replaying bb logs on MWP and nothing changed between the last playable file

LOG00312.TXT

This was made with the exact same logger and Inav 1.7.1 (put no more old than 2 weeks)

Also the battery voltage issued appeared when I moved from 1.6.1 to 1.7.1

I saw there are a lot of blackbox "tidy" commits on github. Do you know how can I revert them from development and try without them?

Thanks for your time

stronnag commented 7 years ago

The way mwp works is that it invokes blackbox_decode to see how many entries there are in the log file (so the user can choose which entry to replay). If blackbox_decode fails to report any valid logs, it shows the "No valid logs" . Otherwise, once the user chooses a log, it invokes mwp's replay_bbox_ltm.rb script with the name of the log file, the log index, and a pipe file descriptor for the script to send back LTM into mwp (so mwp itself has no knowledge of blackbox).

In your file the first log is corrupt (if you ask blackbox_decode for a subsequent log index, it provides data). Coping with this damage for a single user is beyond the call of duty for mwp. However, there is a previously unpublished script bb-split.rb which will split a multi-log blackbox file into its parts. If I run this script and keep parts 2 and 3, thusly::

$ bb-split.rb LOG00352.TXT
./LOG00352_1.TXT
./LOG00352_2.TXT
./LOG00352_3.TXT
$ cat LOG00352_2.TXT LOG00352_3.TXT > LOG00352_fix.TXT

Guess what, we have a valid, non-corrupt blackbox log file!

I have no idea why the initial entry is corrupt, such that blackbox_decode refuses to parse it; it's probably a bug that the chrome app reads it, given the obvious corruption in some fields. Anyway, the split script is now published as bbox-replay/bb-split.rb, and a playable file is attached. LOG00352_fix.TXT image The voltage in the log is still recorded incorrectly. mwp displays that which blackbox_decode reports. Seems like a good basis for an anonymised RCG blog post.

stronnag commented 7 years ago

And, for completeness, my last F1 / serial / OpenLog logs were created on 2017-05-18, firmware based on development commit be7f49ef52f52df4ab950e39b2cd7fa2d00f8936, which includes the "blackbox tidy" changes of 2017-05-14. These logs are not corrupt.

To answer your specific question about reverting changes, well I'm not a git authority by any means but:

# create a private branch
$ git checkout -b xnazeloc
Switched to a new branch 'xnazeloc'
# find the commits to revert ... (not the merge)
$ git log
# revert them
$ git revert 2cca5a9954f9c844bc95e57c420e89857595a39c
[xnazeloc bdcc98c6] Revert "Blackbox tidy"
 1 file changed, 26 insertions(+), 10 deletions(-)
# now build the firmware ...
$ ../mkinav.sh NAZE # my settings (e.g. USE_FLASH_TOOLS for F3)
# ...
arm-none-eabi-size ./obj/main/inav_NAZE.elf
   text    data     bss     dec     hex filename
 127700    1188   16992  145880   239d8 ./obj/main/inav_NAZE.elf
arm-none-eabi-objcopy -O ihex --set-start 0x8000000 obj/main/inav_NAZE.elf obj/inav_1.7.1_NAZE.hex
GCC Version 7.1.0
$ git checkout development # normality, whatever that means
stronnag commented 7 years ago

OTOH,I'm begining to wonder if iNav is more susceptible to generating bad logs than previously? Interesting.

The last log that DzikuVx generated in this iNav thread has 5 entries, only 3 of which hold any data (indices 1 and 3 are just empty, however blackbox_decode copes with this).

....
H features:268959939
E<FF>End of log (disarm reason:4)^@

Do you consider raising an iNav issue about the 'tidy commit' ?

giacomo892 commented 7 years ago

Thanks for all the comments and very informative and instructive content! And sorry for my lag in the answers.

I noticed the first "flight" often get truncated and that's why I often arm the machine, wait 10 seconds and then arming and fly again for a proper logging.

I've also noticed that the quality of the microSD card used in the logger has an impact on the logging. I tough a class 10 one would have done the job but I was wrong not all cards are the same despite BB logging should not require that much bandwith. Maybe we are buffer limited and so slowness of the card cause drops.

Yesterday I've tried another SD card and also switched to Cleanflight fork of openlog (I don't think this impact performaces since openlog just writes serial input to the card) 👍

This is with the new SD. Do you notice some changes from the older logs?

LOG00364.TXT

As you can see the first log is now readable (may be a random coicidence).

I note that beside the fact the logging rate is 1/32 it still not record all the data to the microSD which is very strange since the bit rate should be very low. Could this be a problem with serial speed ? (i've tried 115200 and 250000 having similar results). Seems like I get something like 1/48 - 1/64 and this frame loss may cause issues when decoding.

I've also a feeling that truncated logs are due te fact that when the quad is armed openLog is in a sleep state. It needs to wakeup and it may cause some frame to drop and so it will render the flight unreadable or also due like the first writes on sd are lost for some unknown issue. I may try in the future to prevent the system to sleep and see if it improves. (i don't really think so, since openlog is there since ages. And I do not really know why they power down the atmega 328.. why saving with mA when the motors runs at 30-40A)

Btw I have ordered another SDcard (Sandisk Ultra which is said to be good on docs) and i'll try this weekend (bank holiday too here, so long weekend).

Regarding opening an issue on iNAV I just want to wait to try again INAV 1.6.1 without blackbox tidy commits (there weren't any other mayor commits beside the hardware status logging (https://github.com/iNavFlight/inav/commit/c3e917813d941cb8676b062e76600e254d37d752) and see if the battery is recorded properly and also INAV 1.7 without those commits.