Unusual logging behaviour logging instances of a sensor

Hi all, running into some unusual behaviour attempting to log sensor readings. I’m grabbing the telemetry feed from several HW ESCs and attempting to log the values at each successful read. The messages arrive at roughly 13Hz per ESC thus I am logging at roughly 13*no. of ESCs a second (The telemetry feeds are not necessarily in sync).

I am attempting to create an output as below, where each ESC gets its own log message corresponding to its instance (HET0, HET1, HET2 etc). Each message contains the same data columns though obviously with differing data for each ESC. The data should look like this:

HET0, 56510875, 0.1339198, 0.1339198, 1283, 0.1, 1, 45.5, 191, 193
HET1, 56510918, 0.1319648, 0.1319648, 1261, 0.1, 1, 45.4, 192, 194
HET2, 56510962, 0.1309873, 0.1309873, 1278, 0, 0.8, 45.2, 188, 189
HET3, 56512164, 0.1300098, 0.1300098, 1262, 0.1, 1, 45.2, 187, 191

Instead I am getting the below output:

MSG, 56510859, HET0
HET0, 56510875, 0.1339198, 0.1339198, 1283, 0.1, 1, 45.5, 191, 193
MSG, 56510907, HET1
HET0, 56510918, 0.1319648, 0.1319648, 1261, 0.1, 1, 45.4, 192, 194
MSG, 56510949, HET2
HET0, 56510962, 0.1309873, 0.1309873, 1278, 0, 0.8, 45.2, 188, 189
MSG, 56512145, HET3
HET0, 56512164, 0.1300098, 0.1300098, 1262, 0.1, 1, 45.2, 187, 191

The log write command I issue is as below.

char test[5];
hal.util->snprintf(test, 5, "HET\%1i", state.instance);
GCS_SEND_TEXT(MAV_SEVERITY_WARNING, test);
AP::logger().Write(test,
                   "TimeUS,thr_in,thr_out,rpm,cur_in,cur_out,vol_in,temp_cap,temp_mos",
                   "s%%qAAvOO",
                   "F00000000",
                   "Qffffffff",
                   AP_HAL::micros64(),
                   (double)state.thr_in,
                   (double)state.thr_out,
                   (double)state.rpm,
                   (double)state.cur_in,
                   (double)state.cur_out,
                   (double)state.vol_in,
                   (double)state.temp_cap,
                   (double)state.temp_mos);

I have verified the data being saved is the correct data. Each row, despite being labelled as HET0, is in fact relevant to each seperate ESC. As you can see I print the label string to the console on each write and this executes exactly as expected and yet the log function using the exact same string fails.

I am able to successfully write a single message say HWET with the same contents plus an additional column of the instance, however this destroys any functionality in log analysis or similar as the same message jumps between ESCs and makes it near impossible to graph it in any sensible fashion without first filtering out the unwanted instances.

Better to use per instance logging. Something like this, your log viewer should then split it up for you.

AP::logger().Write("HET",
                   "TimeUS,I,thr_in,thr_out,rpm,cur_in,cur_out,vol_in,temp_cap,temp_mos",
                   "s#%%qAAvOO",
                   "F-00000000",
                   "QBffffffff",
                   AP_HAL::micros64(),
                   state.instance,
                   (double)state.thr_in,
                   (double)state.thr_out,
                   (double)state.rpm,
                   (double)state.cur_in,
                   (double)state.cur_out,
                   (double)state.vol_in,
                   (double)state.temp_cap,
                   (double)state.temp_mos);

image

Oh! I did not realise we were able to split by instance, in that case thats definitely the solution I would be after. Out of curiosity however is there any reason why would the prior implementation not be working? It’s quite unusual.

Thanks mate!

I believe it does a pointer comparison on the log name rather than a string comparison. So you don’t get a new log message type issued because the it thinks name, fields types are all the same.

The headers are only logged once, then the data gets a index to match up with the header.

Very odd, I wonder why it was done that way. Thanks for the heads up on the proper way to implement the instances.

Just in addition to Mr Hall’s responses… Why aren’t you using the
existing “ESC” message for this?

Different parameters for one, there is a fair bit of overlap but its not entirely so and I’d like the complete list to be logged. Its also an entirely separate implementation so best to keep it self contained as such for the time being. As far as I can tell Hobbywing ESCs aren’t supported by the current ESC library, particularly the commercial offering (The X6 / X8 power systems) I’ve built this around. It’s a library specific message, hence the library specific implementation.