Time awareness and smarter logging

[sarfata]

• Make KBox/SK support time so we can parse it and pass it in an SKUpdate
• Parse time in GPS messages from NMEA
• Parse time in GPS messages from NMEA2000
• Implement a Time Manager Service that will set the time on the system
• Show time on the display when we have it
• Add a new option so that we only log when the time is set (default)
• Name the logfile after the time when it was started
• Properly log time in logfile
• Use the SignalK format with a ";" as a delimiter. Second field is the source - closes Log data to SDCard in SignalK update format #12
• Also log -debug- info and error messages in the log file.
• Make sure SDFat also gets the time.
• Parse N2K 129029 for time too
• Log the brand and model of devices on network when we discover them

[coveralls]

Coverage increased (+4.3%) to 71.909% when pulling e5dc7ed on feature/improve-logging into 31fde6f on master.

[ronzeiller]

@sarfata Great feature 👍

For logging of datas: please make it choosable by config settings.
From my point of view we could need 3 different options:

1. Binary file in Actisense format -> smaller file sizes, easy(?) to convert back to N2kMsg
2. Seasmart as it is at the moment
3. SignalK

Background:
I logged my long distance regatta with an own proprietary format type similar to Seasmart.
Now I have a 2.5GB file for playback datas to simulate N2k-bus.
It is great, because I see the first time a "real" N2k-bus working. Sentences are coming with around 180Hz! I do not think that reading/writing of this huge datas would be possible in a Signal K ASCII format.

Note:
when I connected "my KBox" to the boat´s N2k bus, I was disappointed because of a memory leak in my development version, which I never had before with Timo´s N2k-Simulator.
But now I have the log file to do intensive tests on a "real bus".
If you are interested, I can share.

@ Parse date and time in N2k 126992 sentences:
On the mentioned boat were I have the N2k log file from was never sent PGN 126992!
I do not know how common 126992 is.
So parsing PGN 129029 GNSS Position Data might be needed for time (and date)

[sarfata]

Thanks for taking a look @ronzeiller!

From my point of view we could need 3 different options:

• Binary file in Actisense format -> smaller file sizes, easy(?) to convert back to N2kMsg
• Seasmart as it is at the moment
• SignalK

Do you have more details on the Actisense binary file format? What does it look like?

We can always add more but I am afraid that if we support too many things we will not test them and they will slowly stop working and become abandoned. I would rather find one format that works for everyone. We could replace PCDIN by Actisense serialized format but I do not think it will be much smaller.

I agree that on a modern boat, logging everything is very likely going to be way too much. Especially if we log the NME2000 message AND the translation into SignalK.

I am going to do some more testing before I merge this and maybe I will disable logging by default. I think what most people really want is one CSV line per second with current boat data. Not all the NMEA2000 messages.

So parsing PGN 129029 GNSS Position Data might be needed for time (and date)

Did you already do that in your branch? Can I take it?

[ronzeiller]

So parsing PGN 129029 GNSS Position Data might be needed for time (and date)

Did you already do that in your branch? Can I take it?

No, because time in SKUpdate is new to me.
But I could take care of that if you like

Also see some general, very good informations from Timo here:
ttlappalainen/NMEA2000#72

[ronzeiller]

From my point of view we could need 3 different options:

Binary file in Actisense format -> smaller file sizes, easy(?) to convert back to N2kMsg
Seasmart as it is at the moment
SignalK

Do you have more details on the Actisense binary file format? What does it look like?

Sorry, too fast writing without thinking....
Digged out some conversation with Timo about Actisense binary and logging: ttlappalainen/NMEA2000#75

No, the Actisense serialized format is larger than Seasmart.

But we could save some bytes with a shorted message:

pcdin_sentence_length = 6+1+6+1+8+1+2+1+msg.DataLen*2+1+2 + 1;
6	$PCDIN
1	,
6	PGN
1	,
8	timestamp
1	,
2	Source
1	,
variable Data
1	?
2	*
1	checksum

13 Bytes could be saved per sentence if we drop redundant "$PCDIN", all commas and the checksum

UTC could be written in the first line of log file, then afterwards just millis() are needed as timestamp to get real time of each sentence.

The basic question is what is really needed in a log file and what do users want to do with it?
Who is really looking in a csv-file to find out datas at xy time?

But you are definitely right if you say for that application it is just needed to write informations every 1....4 seconds.

I was logging datas for years with Expedition, but the only thing which was really interesting was the "Playback" function to see the boat with speed and wind datas moving in a chart.
Example of Expedition log, which is a huge csv file:

Utc,Bsp,Awa,Aws,Twa,Tws,Twd,Rudder2,Leeway,Set,Drift,Hdg,Air temp,Sea temp,Baro,Depth,Heel,Trim,Rudder,Tab,Forestay,Downhaul,MastAng,FrstyLen,MastButt,Load S,Load P,Rake,Volts,ROT,Gps qual,PDOP,Gps num,Gps age,Altitude,Geo sep,Gps mode,Lat,Lon,Cog,Sog,Diff stn,Error,StbRunnr,PrtRunnr,Vang,Traveller,MainSheet,Keel ang,Keel ht,CanardH,Oil P,RPM 1,RPM 2,Board,Board 2,DistToLn,RchTmToLn,RchDtToLn,GPS Time,Twd+90,Twd-90,Downhaul2,Mk Lat,Mk Lon,Port lat,Port lon,Stbd lat,Stbd lon,HPE,RH,Lead P,Lead S,BackStay,User 0,User 1,User 2,User 3,User 4,User 5,User 6,User 7,User 8,User 9,User 10,User 11,User 12,User 13,User 14,User 15,User 16,User 17,User 18,User 19,User 20,User 21,User 22,User 23,User 24,User 25,User 26,User 27,User 28,User 29,User 30,User 31,TmToGun,TmToLn,TmToBurn,BelowLn,GunBlwLn,WvSigHt,WvSigPd,WvMaxHt,WvMaxPd,Slam,Motion,Mwa,Mws,Boom Pos
42100.916663,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,102.1,282.1
42100.916667,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,102.1,282.1
42100.91667,,,,,,17.1,,,225.7,2.9,115,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,,107.1,287.1

A completely other thing is testing KBox on different systems and here it is good to have all N2k-sentences of many real systems.
This is why I suggested to have a "Write everything, but fast and small"-format.
May be we can get N2k log files from other KBox or DIY-N2k-interface users for testing KBox under different circumstances.

[sarfata]

@ronzeiller With the PR as it is we log every NMEA2000 messages but user can disable this. I am going to test this on my boat and see how it performs. Please let me know what you think too. The other important thing here is that we will have system logs and stats in the logfiles. Should make it a lot easier to understand some crashes in the future, especially WiFi module crashes.

If you have some $PCDIN logs for 129029 I will add support for it.

And, if you could share your giant log file that would be very appreciated. I can use this for testing in the future. I am also very interested in the visualization part. I think Expedition is what most people use to look at the data but there must be something better we can do!

[ronzeiller]

@sarfata

And, if you could share your giant log file that would be very appreciated. I can use this for testing in the future. I am also very interested in the visualization part. I think Expedition is what most people use to look at the data but there must be something better we can do!

https://github.com/ronzeiller/N2kLogReaderWriter
It is working, but more or less very rough and dirty programmed and I am not very happy with the delay() section to simulate real timing.
If you find the time I would be happy to get your ideas to improve it.

If you have some $PCDIN logs for 129029 I will add support for it.

You will find this sentence in the log files RPC2018.log and RPC2018_xad.log (were the Garmin GPSMap 721 was turned on)
It is coming with around 10Hz.
Which brings me back to the thought: "Who needs 10 Hz datas on output?"
If it isn´t used for internal calculations or an Autopilot connected, probably nobody.....
(The rough idea is to do a downsampling/filtering/damping in SKHub and services and pages could subscribe to low-frequency SKUpdates)

Please note the Manufacturer and Product Informations in the log file.

I was writing these informations the first 30 seconds into the log file.
Code taken from Timo´s examples: DeviceAnalyzer.ino
You see the informations coming in little by little until all information were completed. (Multi parted PGNs?)
May be something to log too for this PR?

[ronzeiller]

Autorotate log file when 1 GB

I would suggest to do autorotate of log file by end of day ?

[sarfata]

Going to merge this PR as-is. I have created tickets to not forget about your two suggestions.

I would suggest to do autorotate of log file by end of day ?

That would be easy to add but right now the time is UTC based which means "ends of day" is kind of meaningless. Let's revisit this idea when we have a setting for the local timezone.