Vsevolod,
Glad to see you found a way to fix the problem!
However, I'm not really sure whether it's the right solution. You are calling the cressi_leonardo_transfer_prepare() function from inside the cressi_leonardo_packet() function. That means you're doing this for every single packet! But if the problem is only during the initial setup of the connection, then that's probably overkill. Note that due to the 300ms sleep in that function, there is also a serious impact on the performance. So you are probably correct that the setup phase needs some tweaking, but I doubt this is necessary for every single packet.
I went back to have a look at some of the capture files I have, and the Cressi application doesn't seem to change DTR or RTS between packets. But it does this sequence at startup:
CREATE Options: Open GET_BAUD_RATE GET_LINE_CONTROL GET_CHARS GET_HANDFLOW SET_BAUD_RATE Rate: 9600 SET_RTS SET_DTR SET_LINE_CONTROL StopBits: 1 Parity: NONE WordLength: 8 SET_CHAR EOF:0 ERR:0 BRK:0 EVT:0 XON:11 XOFF:13 SET_HANDFLOW Shake:1 Replace:40 XonLimit:64 XoffLimit:64 SET_QUEUE_SIZE InSize: 640 OutSize: 640 SET_TIMEOUTS RI:-1 RM:0 RC:0 WM:0 WC:500 SET_RTS SET_DTR GET_BAUD_RATE GET_LINE_CONTROL GET_CHARS GET_HANDFLOW SET_BAUD_RATE Rate: 115200 SET_RTS SET_DTR SET_LINE_CONTROL StopBits: 1 Parity: NONE WordLength: 8 SET_CHAR EOF:0 ERR:0 BRK:0 EVT:0 XON:11 XOFF:13 SET_HANDFLOW Shake:1 Replace:40 XonLimit:64 XoffLimit:64 GET_BAUD_RATE GET_LINE_CONTROL GET_CHARS GET_HANDFLOW SET_QUEUE_SIZE InSize: 640 OutSize: 640 SET_TIMEOUTS RI:-1 RM:0 RC:0 WM:0 WC:500 GET_BAUD_RATE GET_LINE_CONTROL GET_CHARS GET_HANDFLOW SET_BAUD_RATE Rate: 115200 SET_RTS SET_DTR SET_LINE_CONTROL StopBits: 1 Parity: NONE WordLength: 8 SET_CHAR EOF:0 ERR:0 BRK:0 EVT:0 XON:11 XOFF:13 SET_HANDFLOW Shake:1 Replace:40 XonLimit:64 XoffLimit:64 GET_BAUD_RATE GET_LINE_CONTROL GET_CHARS GET_HANDFLOW SET_QUEUE_SIZE InSize: 640 OutSize: 640 SET_TIMEOUTS RI:-1 RM:0 RC:0 WM:0 WC:500 CLR_DTR SET_DTR CLR_DTR WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D FLUSH_BUFFERS SET_TIMEOUTS RI:-1 RM:0 RC:10000 WM:0 WC:500 READ 7B 30 31 43 30 32 36 30 30 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 46 30 31 30 35 30 31 43 41 39 31 7D
So it first sets DTR and RTS:
SET_RTS SET_DTR
(The fact that this happens a few times is probably due to use of some serial port package that doesn't change all settings at once. The libdivecomputer configure function does this with just one call.)
And then before sending the first command it toggles DTR:
CLR_DTR SET_DTR CLR_DTR
And that might be the key to the solution, because libdivecomputer only does this:
SET_RTS SET_DTR
CLR_DTR
So an extra SET_DTR and CLR_DTR at startup, with the right amount of delays in between, might already be sufficient.
There is also a difference in behavior in this area between the windows and linux serial port code. Those initial SET_RTS and SET_DTR are there, because the windows api automatically sets or clears RTS and DTR when configuring the serial lines settings (based on the dcb.fDtrControl and dcb.fRtsControl settings). But on linux, the DTR/RTS lines are left alone, and you need to control them manually. That might explain why everything works on windows, but not on linux.
So I think we need to do the following sequence:
SET_RTS SET_DTR <- This can probably be omitted, but it makes sure windows and linux behave the same CLR_DTR SET_DTR CLR_DTR
RTS only needs to be set once, but the dive computer probably reacts to the DTR toggling, so that's the part that matters I think. And we need some delays in between to make sure it doesn't happen too fast. When I reverse engineered this, I just looked at the final value for DTR (plus the initial set to get the same result on windows and linux), but now I think it's the toggling that does the trick.
So in libdivecomputer calls that would translate to the following sequence. First initialize the serial port settings, making sure windows and linux are the same:
dc_serial_configure (device->port, 115200, 8, DC_PARITY_NONE, DC_STOPBITS_ONE, DC_FLOWCONTROL_NONE) dc_serial_set_timeout (device->port, 1000); dc_serial_set_rts (device->port, 1); dc_serial_set_dtr (device->port, 1);
Then discard garbage data as usual:
dc_serial_sleep (device->port, 100); dc_serial_purge (device->port, DC_DIRECTION_ALL);
And finally toggle the DTR line:
dc_serial_set_dtr (device->port, 0); dc_serial_sleep (device->port, SOMEDELAY); dc_serial_set_dtr (device->port, 1); dc_serial_sleep (device->port, SOMEDELAY); dc_serial_set_dtr (device->port, 0);
I only don't know how long the delays should be, because I have no timing info in the capture file.
Does that make sense?
Jef
On 2017-10-01 13:38, Vsevolod Velichko wrote:
Cressi Leonardo computers behave extremely unreliable if the dump is requested right after the connection establishment. The computer mostly sends nothing or sends garbage, so official Cressi software uses request of small device memory part as a ping until device become stable. And DTR flag should be reset before each request, or device wouldn't send any data in response.
This patch fixes https://github.com/Subsurface-divelog/subsurface/issues/391 and probably all previous mentions of Leonardo problems.
Signed-off-by: Vsevolod Velichko torkvemada@sorokdva.net
src/cressi_leonardo.c | 133 +++++++++++++++++++++++++++++++++----------------- 1 file changed, 89 insertions(+), 44 deletions(-)
diff --git a/src/cressi_leonardo.c b/src/cressi_leonardo.c index f21a223..14db35f 100644 --- a/src/cressi_leonardo.c +++ b/src/cressi_leonardo.c @@ -44,7 +44,10 @@ #define RB_PROFILE_END SZ_MEMORY #define RB_PROFILE_DISTANCE(a,b) ringbuffer_distance (a, b, 0, RB_PROFILE_BEGIN, RB_PROFILE_END)
-#define MAXRETRIES 4 +#define PING_ADDRESS 0x1000 +#define PING_LENGTH 19
+#define MAXRETRIES 20 #define PACKETSIZE 32
typedef struct cressi_leonardo_device_t { @@ -74,6 +77,9 @@ static const dc_device_vtable_t cressi_leonardo_device_vtable = { static dc_status_t cressi_leonardo_extract_dives (dc_device_t *abstract, const unsigned char data[], unsigned int size, dc_dive_callback_t callback, void *userdata);
+static dc_status_t +cressi_leonardo_transfer_prepare (cressi_leonardo_device_t *device, dc_context_t *context);
static void cressi_leonardo_make_ascii (const unsigned char raw[], unsigned int rsize, unsigned char ascii[], unsigned int asize) { @@ -105,6 +111,13 @@ cressi_leonardo_packet (cressi_leonardo_device_t *device, const unsigned char co if (device_is_cancelled (abstract)) return DC_STATUS_CANCELLED;
- // Prepare device for writing.
- status = cressi_leonardo_transfer_prepare (device,
abstract->context);
- if (status != DC_STATUS_SUCCESS) {
ERROR (abstract->context, "Failed to prepare device for transfer.");return status;- }
- // Send the command to the device. status = dc_serial_write (device->port, command, csize, NULL); if (status != DC_STATUS_SUCCESS) {
@@ -141,6 +154,37 @@ cressi_leonardo_packet (cressi_leonardo_device_t *device, const unsigned char co }
static dc_status_t +cressi_leonardo_transfer_prepare (cressi_leonardo_device_t *device, dc_context_t *context) +{
- // Set the RTS line.
- dc_status_t status = dc_serial_set_rts (device->port, 1);
- if (status != DC_STATUS_SUCCESS) {
ERROR (context, "Failed to set the RTS line.");return status;- }
- // Set the DTR line.
- status = dc_serial_set_dtr (device->port, 1);
- if (status != DC_STATUS_SUCCESS) {
ERROR (context, "Failed to set the DTR line.");return status;- }
- dc_serial_sleep (device->port, 200);
- // Clear the DTR line.
- status = dc_serial_set_dtr (device->port, 0);
- if (status != DC_STATUS_SUCCESS) {
ERROR (context, "Failed to clear the DTR line.");return status;- }
- dc_serial_sleep (device->port, 100);
- dc_serial_purge (device->port, DC_DIRECTION_ALL);
- return status;
+}
+static dc_status_t cressi_leonardo_transfer (cressi_leonardo_device_t *device, const unsigned char command[], unsigned int csize, unsigned char answer[], unsigned int asize) { unsigned int nretries = 0; @@ -197,39 +241,13 @@ cressi_leonardo_device_open (dc_device_t **out, dc_context_t *context, const cha goto error_close; }
- // Set the timeout for receiving data (1000 ms).
- status = dc_serial_set_timeout (device->port, 1000);
- // Set the timeout for receiving data (3000 ms).
- status = dc_serial_set_timeout (device->port, 3000); if (status != DC_STATUS_SUCCESS) { ERROR (context, "Failed to set the timeout."); goto error_close; }
// Set the RTS line.
status = dc_serial_set_rts (device->port, 1);
if (status != DC_STATUS_SUCCESS) {
ERROR (context, "Failed to set the RTS line.");goto error_close;}
// Set the DTR line.
status = dc_serial_set_dtr (device->port, 1);
if (status != DC_STATUS_SUCCESS) {
ERROR (context, "Failed to set the DTR line.");goto error_close;}
dc_serial_sleep (device->port, 200);
// Clear the DTR line.
status = dc_serial_set_dtr (device->port, 0);
if (status != DC_STATUS_SUCCESS) {
ERROR (context, "Failed to clear the DTR line.");goto error_close;}
dc_serial_sleep (device->port, 100);
dc_serial_purge (device->port, DC_DIRECTION_ALL);
*out = (dc_device_t *) device;
return DC_STATUS_SUCCESS;
@@ -332,29 +350,56 @@ cressi_leonardo_device_dump (dc_device_t *abstract, dc_buffer_t *buffer) progress.maximum = SZ_MEMORY; device_event_emit (abstract, DC_EVENT_PROGRESS, &progress);
- // Send the command header to the dive computer.
- const unsigned char command[] = {0x7B, 0x31, 0x32, 0x33, 0x44, 0x42,
0x41, 0x7d};
- status = dc_serial_write (device->port, command, sizeof (command),
NULL);
- if (status != DC_STATUS_SUCCESS) {
ERROR (abstract->context, "Failed to send the command.");return status;
- for (int attempt = 0; attempt < MAXRETRIES; ++attempt) {
// Send the ping command to the dive computer.unsigned char tmp[PING_LENGTH] = {0};status = cressi_leonardo_device_read(abstract, PING_ADDRESS, tmp,sizeof(tmp));
if (status == DC_STATUS_SUCCESS)break;
- // Receive the header packet.
- unsigned char header[7] = {0};
- status = dc_serial_read (device->port, header, sizeof (header),
NULL); if (status != DC_STATUS_SUCCESS) {
ERROR (abstract->context, "Failed to receive the answer.");
ERROR (abstract->context, "Failed to ping device.");
- // Verify the header packet.
- const unsigned char expected[] = {0x7B, 0x21, 0x44, 0x35, 0x42, 0x33,
0x7d};
- if (memcmp (header, expected, sizeof (expected)) != 0) {
ERROR (abstract->context, "Unexpected answer byte.");return DC_STATUS_PROTOCOL;
- for (int attempt = 0; attempt < MAXRETRIES; ++attempt) {
status = cressi_leonardo_transfer_prepare (device,abstract->context);
if (status != DC_STATUS_SUCCESS) {ERROR (abstract->context, "Failed to prepare device fortransfer.");
continue;}// Send the command header to the dive computer.const unsigned char command[] = {0x7B, 0x31, 0x32, 0x33, 0x44,0x42, 0x41, 0x7d};
status = dc_serial_write (device->port, command, sizeof (command),NULL);
if (status != DC_STATUS_SUCCESS) {ERROR (abstract->context, "Failed to send the command.");continue;}// Receive the header packet.unsigned char header[7] = {0};status = dc_serial_read (device->port, header, sizeof (header),NULL);
if (status != DC_STATUS_SUCCESS) {ERROR (abstract->context, "Failed to receive the answer.");continue;}// Verify the header packet.const unsigned char expected[] = {0x7B, 0x21, 0x44, 0x35, 0x42,0x33, 0x7d};
if (memcmp (header, expected, sizeof (expected)) != 0) {ERROR (abstract->context, "Unexpected answer byte.");status = DC_STATUS_PROTOCOL;continue;}break;}
if (status != DC_STATUS_SUCCESS)
return status;unsigned char *data = dc_buffer_get_data (buffer);
unsigned int nbytes = 0;
Jef,
Thanks for your feedback! I've experimented with the transfer for some time and finally found that without those "ping" packages it really never works for some reason, regardless how hard do we try to purge incoming garbage data. There's a working version of the script[1], which successfully dumps the data on each call, but if I remove first ping() or call dtr-toggle just once at startup, it failed to receive the dump. I'll try to do double-toggle at startup later today, may be it'll help.
Regading the delays, here I attach the pcap file from the Windows Cressi software. I was unable to find which packets correspond with the set_dtr or clr_dtr, but if you can decode them, they come along with the timings. There was two connections of the computer to the adapter inside (hence also two full dumps of the data), first request of dump comes at packet 2484, and the second one is at the packet 6069.
[1] http://paste.ubuntu.com/25660082/
Jef,
I just tested your idea, so here are the results: 1. Double toggle on-off of DTR flag appears to be changing nothing. It still works if it is done before each message, and it still fails if it's done only once at startup. 2. Removal of the ping is definitely leads to fail. In most cases it looks like hang-up in the middle of dump sending. I have no idea for what reason. 3. Good news is that delays can be slightly decreased, so in modified patch below it's 120 ms instead of 300 ms.
In fact I suppose that this delay in each message shouldn't be considered something awful since in most cases it's done only 2-3 times before full dump, and the multiple random access to device memory is hardly ever used. So I attach the modified version of the patch with decreased delays.
Signed-off-by: Vsevolod Velichko torkvemada@sorokdva.net --- src/cressi_leonardo.c | 133 +++++++++++++++++++++++++++++++++----------------- 1 file changed, 89 insertions(+), 44 deletions(-)
diff --git a/src/cressi_leonardo.c b/src/cressi_leonardo.c index f21a223..14db35f 100644 --- a/src/cressi_leonardo.c +++ b/src/cressi_leonardo.c @@ -44,7 +44,10 @@ #define RB_PROFILE_END SZ_MEMORY #define RB_PROFILE_DISTANCE(a,b) ringbuffer_distance (a, b, 0, RB_PROFILE_BEGIN, RB_PROFILE_END)
-#define MAXRETRIES 4 +#define PING_ADDRESS 0x1000 +#define PING_LENGTH 19 + +#define MAXRETRIES 20 #define PACKETSIZE 32
typedef struct cressi_leonardo_device_t { @@ -74,6 +77,9 @@ static const dc_device_vtable_t cressi_leonardo_device_vtable = { static dc_status_t cressi_leonardo_extract_dives (dc_device_t *abstract, const unsigned char data[], unsigned int size, dc_dive_callback_t callback, void *userdata);
+static dc_status_t +cressi_leonardo_transfer_prepare (cressi_leonardo_device_t *device, dc_context_t *context); + static void cressi_leonardo_make_ascii (const unsigned char raw[], unsigned int rsize, unsigned char ascii[], unsigned int asize) { @@ -105,6 +111,13 @@ cressi_leonardo_packet (cressi_leonardo_device_t *device, const unsigned char co if (device_is_cancelled (abstract)) return DC_STATUS_CANCELLED;
+ // Prepare device for writing. + status = cressi_leonardo_transfer_prepare (device, abstract->context); + if (status != DC_STATUS_SUCCESS) { + ERROR (abstract->context, "Failed to prepare device for transfer."); + return status; + } + // Send the command to the device. status = dc_serial_write (device->port, command, csize, NULL); if (status != DC_STATUS_SUCCESS) { @@ -141,6 +154,37 @@ cressi_leonardo_packet (cressi_leonardo_device_t *device, const unsigned char co }
static dc_status_t +cressi_leonardo_transfer_prepare (cressi_leonardo_device_t *device, dc_context_t *context) +{ + // Set the RTS line. + dc_status_t status = dc_serial_set_rts (device->port, 1); + if (status != DC_STATUS_SUCCESS) { + ERROR (context, "Failed to set the RTS line."); + return status; + } + + // Set the DTR line. + status = dc_serial_set_dtr (device->port, 1); + if (status != DC_STATUS_SUCCESS) { + ERROR (context, "Failed to set the DTR line."); + return status; + } + + dc_serial_sleep (device->port, 100); + + // Clear the DTR line. + status = dc_serial_set_dtr (device->port, 0); + if (status != DC_STATUS_SUCCESS) { + ERROR (context, "Failed to clear the DTR line."); + return status; + } + + dc_serial_sleep (device->port, 20); + dc_serial_purge (device->port, DC_DIRECTION_ALL); + return status; +} + +static dc_status_t cressi_leonardo_transfer (cressi_leonardo_device_t *device, const unsigned char command[], unsigned int csize, unsigned char answer[], unsigned int asize) { unsigned int nretries = 0; @@ -197,39 +241,13 @@ cressi_leonardo_device_open (dc_device_t **out, dc_context_t *context, const cha goto error_close; }
- // Set the timeout for receiving data (1000 ms). - status = dc_serial_set_timeout (device->port, 1000); + // Set the timeout for receiving data (3000 ms). + status = dc_serial_set_timeout (device->port, 3000); if (status != DC_STATUS_SUCCESS) { ERROR (context, "Failed to set the timeout."); goto error_close; }
- // Set the RTS line. - status = dc_serial_set_rts (device->port, 1); - if (status != DC_STATUS_SUCCESS) { - ERROR (context, "Failed to set the RTS line."); - goto error_close; - } - - // Set the DTR line. - status = dc_serial_set_dtr (device->port, 1); - if (status != DC_STATUS_SUCCESS) { - ERROR (context, "Failed to set the DTR line."); - goto error_close; - } - - dc_serial_sleep (device->port, 200); - - // Clear the DTR line. - status = dc_serial_set_dtr (device->port, 0); - if (status != DC_STATUS_SUCCESS) { - ERROR (context, "Failed to clear the DTR line."); - goto error_close; - } - - dc_serial_sleep (device->port, 100); - dc_serial_purge (device->port, DC_DIRECTION_ALL); - *out = (dc_device_t *) device;
return DC_STATUS_SUCCESS; @@ -332,29 +350,56 @@ cressi_leonardo_device_dump (dc_device_t *abstract, dc_buffer_t *buffer) progress.maximum = SZ_MEMORY; device_event_emit (abstract, DC_EVENT_PROGRESS, &progress);
- // Send the command header to the dive computer. - const unsigned char command[] = {0x7B, 0x31, 0x32, 0x33, 0x44, 0x42, 0x41, 0x7d}; - status = dc_serial_write (device->port, command, sizeof (command), NULL); - if (status != DC_STATUS_SUCCESS) { - ERROR (abstract->context, "Failed to send the command."); - return status; + for (int attempt = 0; attempt < MAXRETRIES; ++attempt) { + // Send the ping command to the dive computer. + unsigned char tmp[PING_LENGTH] = {0}; + status = cressi_leonardo_device_read(abstract, PING_ADDRESS, tmp, sizeof(tmp)); + if (status == DC_STATUS_SUCCESS) + break; }
- // Receive the header packet. - unsigned char header[7] = {0}; - status = dc_serial_read (device->port, header, sizeof (header), NULL); if (status != DC_STATUS_SUCCESS) { - ERROR (abstract->context, "Failed to receive the answer."); + ERROR (abstract->context, "Failed to ping device."); return status; }
- // Verify the header packet. - const unsigned char expected[] = {0x7B, 0x21, 0x44, 0x35, 0x42, 0x33, 0x7d}; - if (memcmp (header, expected, sizeof (expected)) != 0) { - ERROR (abstract->context, "Unexpected answer byte."); - return DC_STATUS_PROTOCOL; + for (int attempt = 0; attempt < MAXRETRIES; ++attempt) { + status = cressi_leonardo_transfer_prepare (device, abstract->context); + if (status != DC_STATUS_SUCCESS) { + ERROR (abstract->context, "Failed to prepare device for transfer."); + continue; + } + + // Send the command header to the dive computer. + const unsigned char command[] = {0x7B, 0x31, 0x32, 0x33, 0x44, 0x42, 0x41, 0x7d}; + status = dc_serial_write (device->port, command, sizeof (command), NULL); + if (status != DC_STATUS_SUCCESS) { + ERROR (abstract->context, "Failed to send the command."); + continue; + } + + // Receive the header packet. + unsigned char header[7] = {0}; + status = dc_serial_read (device->port, header, sizeof (header), NULL); + if (status != DC_STATUS_SUCCESS) { + ERROR (abstract->context, "Failed to receive the answer."); + continue; + } + + // Verify the header packet. + const unsigned char expected[] = {0x7B, 0x21, 0x44, 0x35, 0x42, 0x33, 0x7d}; + if (memcmp (header, expected, sizeof (expected)) != 0) { + ERROR (abstract->context, "Unexpected answer byte."); + status = DC_STATUS_PROTOCOL; + continue; + } + + break; }
+ if (status != DC_STATUS_SUCCESS) + return status; + unsigned char *data = dc_buffer_get_data (buffer);
unsigned int nbytes = 0;
On 2017-10-03 00:15, Vsevolod Velichko wrote:
I just tested your idea, so here are the results:
- Double toggle on-off of DTR flag appears to be changing nothing. It
still works if it is done before each message, and it still fails if it's done only once at startup. 2. Removal of the ping is definitely leads to fail. In most cases it looks like hang-up in the middle of dump sending. I have no idea for what reason.
Can you send me some logs from those experiments? It will help me understand what's going on.
What values did you use for the delays?
- Good news is that delays can be slightly decreased, so in modified
patch below it's 120 ms instead of 300 ms.
In fact I suppose that this delay in each message shouldn't be considered something awful since in most cases it's done only 2-3 times before full dump, and the multiple random access to device memory is hardly ever used.
You are right that libdivecomputer doesn't use random access internally, but there might be applications using it. It will for example also prevent us from optimizing the foreach implementation to download only the data we really need, instead of just downloading a full memory dump and extracting the parts we need. (I've no idea if this is actually worth doing or not.)
Anyway, I'm not really convinced that the dtr toggling and the delay is necessary on every packet. When I look through my capture files, then I have the impression that once the first packet is received correctly, the connection is stable. I see indeed lots of attempts for the first packet (and the cressi application even re-opens the serial port, which doesn't make any sense at all). But once the data starts flowing, the cressi application doesn't touch the serial line settings. That (combined with the fact that on Windows the current code works fine) is why I think this is unnecessary.
If the DTR toggling at startup alone isn't enough, then we probably need some sort of "pinging". But I still think the dtr toggling and delay is only needed there, and not for every packet. For example a more optimal solution might already be to integrate that code into the existing retry loop in the cressi_leonardo_transfer() function. That way, if the first attempt works immediately, then there will be no delay and thus also no performance problem. Only when transmitting a packet fails, we do the whole dtr toggling with delay before retrying again. In that case, the extra delay is fine, because there is a problem anyway.
I've attached a capture file. It's created with portmon (which unfortunately only works on 32-bit windows). This kind of capture file is a lot easier to interpret than the pcap capture because you don't have to deal with the overhead of the ftdi usb-serial chip.
The complete download session is from line 2192 to 31959. These are the commands that are being send:
WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D -> {100000139306} WRITE 7B 31 30 33 30 30 30 30 38 44 46 42 43 7D -> {10300008DFBC} WRITE 7B 31 30 34 30 30 30 30 31 38 36 44 34 7D -> {1040000186D4} WRITE 7B 31 30 35 30 30 30 30 31 43 33 37 34 7D -> {10500001C374} WRITE 7B 31 30 36 30 30 30 30 46 30 33 45 34 7D -> {1060000F03E4} WRITE 7B 31 30 38 30 30 30 30 31 38 44 33 37 7D -> {108000018D37} WRITE 7B 31 30 38 32 30 30 30 41 42 37 32 33 7D -> {1082000AB723} WRITE 7B 31 30 39 30 30 30 31 30 45 42 38 37 7D -> {10900010EB87} WRITE 7B 31 32 33 44 42 41 7D -> {123DBA}
WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D WRITE 7B 31 30 33 30 30 30 30 38 44 46 42 43 7D WRITE 7B 31 30 34 30 30 30 30 31 38 36 44 34 7D WRITE 7B 31 30 35 30 30 30 30 31 43 33 37 34 7D WRITE 7B 31 30 36 30 30 30 30 46 30 33 45 34 7D WRITE 7B 31 30 38 30 30 30 30 31 38 44 33 37 7D WRITE 7B 31 30 38 32 30 30 30 41 42 37 32 33 7D WRITE 7B 31 30 39 30 30 30 31 30 45 42 38 37 7D WRITE 7B 31 32 33 44 42 41 7D
WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D -> {100000139306} WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D -> {100000139306} WRITE 7B 32 32 36 38 45 39 7D -> {2268E9}
(Not sure why, but there are two full downloads in there. I also don't know what that last command does.)
If you look closely at this part, you can clearly see that the line settings are changed only at startup, and then again just before the {123DBA} dump command. But it looks like it's only increasing the buffer size (from 640 to 80960). All other settings (including DTR and RTS) remain at their current values.
Jef
Can you send me some logs from those experiments? It will help me understand what's going on.
Sure. I've attached them with corresponding outputs and dumps from wireshark. See the comments about differences and effects at the beginning of each .py file.
Not sure why, but there are two full downloads in there. I also don't know what that last command does.
I tested it and it is a command to force DC to turn off. So computer probably was later reattached, and Cressi software automatically starts download when connection is detected.
2017-10-03 11:20 GMT+03:00 Jef Driesen jef@libdivecomputer.org:
On 2017-10-03 00:15, Vsevolod Velichko wrote:
I just tested your idea, so here are the results:
- Double toggle on-off of DTR flag appears to be changing nothing. It
still works if it is done before each message, and it still fails if it's done only once at startup. 2. Removal of the ping is definitely leads to fail. In most cases it looks like hang-up in the middle of dump sending. I have no idea for what reason.
Can you send me some logs from those experiments? It will help me understand what's going on.
What values did you use for the delays?
- Good news is that delays can be slightly decreased, so in modified
patch below it's 120 ms instead of 300 ms.
In fact I suppose that this delay in each message shouldn't be considered something awful since in most cases it's done only 2-3 times before full dump, and the multiple random access to device memory is hardly ever used.
You are right that libdivecomputer doesn't use random access internally, but there might be applications using it. It will for example also prevent us from optimizing the foreach implementation to download only the data we really need, instead of just downloading a full memory dump and extracting the parts we need. (I've no idea if this is actually worth doing or not.)
Anyway, I'm not really convinced that the dtr toggling and the delay is necessary on every packet. When I look through my capture files, then I have the impression that once the first packet is received correctly, the connection is stable. I see indeed lots of attempts for the first packet (and the cressi application even re-opens the serial port, which doesn't make any sense at all). But once the data starts flowing, the cressi application doesn't touch the serial line settings. That (combined with the fact that on Windows the current code works fine) is why I think this is unnecessary.
If the DTR toggling at startup alone isn't enough, then we probably need some sort of "pinging". But I still think the dtr toggling and delay is only needed there, and not for every packet. For example a more optimal solution might already be to integrate that code into the existing retry loop in the cressi_leonardo_transfer() function. That way, if the first attempt works immediately, then there will be no delay and thus also no performance problem. Only when transmitting a packet fails, we do the whole dtr toggling with delay before retrying again. In that case, the extra delay is fine, because there is a problem anyway.
I've attached a capture file. It's created with portmon (which unfortunately only works on 32-bit windows). This kind of capture file is a lot easier to interpret than the pcap capture because you don't have to deal with the overhead of the ftdi usb-serial chip.
The complete download session is from line 2192 to 31959. These are the commands that are being send:
WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D -> {100000139306} WRITE 7B 31 30 33 30 30 30 30 38 44 46 42 43 7D -> {10300008DFBC} WRITE 7B 31 30 34 30 30 30 30 31 38 36 44 34 7D -> {1040000186D4} WRITE 7B 31 30 35 30 30 30 30 31 43 33 37 34 7D -> {10500001C374} WRITE 7B 31 30 36 30 30 30 30 46 30 33 45 34 7D -> {1060000F03E4} WRITE 7B 31 30 38 30 30 30 30 31 38 44 33 37 7D -> {108000018D37} WRITE 7B 31 30 38 32 30 30 30 41 42 37 32 33 7D -> {1082000AB723} WRITE 7B 31 30 39 30 30 30 31 30 45 42 38 37 7D -> {10900010EB87} WRITE 7B 31 32 33 44 42 41 7D -> {123DBA}
WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D WRITE 7B 31 30 33 30 30 30 30 38 44 46 42 43 7D WRITE 7B 31 30 34 30 30 30 30 31 38 36 44 34 7D WRITE 7B 31 30 35 30 30 30 30 31 43 33 37 34 7D WRITE 7B 31 30 36 30 30 30 30 46 30 33 45 34 7D WRITE 7B 31 30 38 30 30 30 30 31 38 44 33 37 7D WRITE 7B 31 30 38 32 30 30 30 41 42 37 32 33 7D WRITE 7B 31 30 39 30 30 30 31 30 45 42 38 37 7D WRITE 7B 31 32 33 44 42 41 7D
WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D -> {100000139306} WRITE 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D -> {100000139306} WRITE 7B 32 32 36 38 45 39 7D -> {2268E9}
(Not sure why, but there are two full downloads in there. I also don't know what that last command does.)
If you look closely at this part, you can clearly see that the line settings are changed only at startup, and then again just before the {123DBA} dump command. But it looks like it's only increasing the buffer size (from 640 to 80960). All other settings (including DTR and RTS) remain at their current values.
Jef
On 2017-10-03 23:58, Vsevolod Velichko wrote:
Can you send me some logs from those experiments? It will help me understand what's going on.
Sure. I've attached them with corresponding outputs and dumps from wireshark. See the comments about differences and effects at the beginning of each .py file.
With those python scripts it's a bit harder to see what's going on, compared to the libdivecomputer logging where everything is in a single file. It's also not exactly the same. Especially the reading is subtle different. You have some 10ms sleep calls there. I don't think that will make a difference, but you never know. After all, it's some subtle difference that we're trying to find.
Have you tried my suggestion of doing the DTR toggling in the existing retry code? Something like the attached patch (the pinging is commented out, so try with and without). That should behave almost the same as your working code. It will do the DTR toggling during setup. And as long as the packet fails, it will keep doing the DTR toggling. But once the first packet is received correctly and the connection is stable, it's no longer done except when packets start to fail again.
Can you try to capture the serial communication between the cressi application and the dive computer. But with a serial sniffer instead of the wireshark. I would like to have a look at the timings, but ideally I would like to avoid having to look into the details of the ftdi (and usb) protocol overhead.
If you have a 32-bit windows, then you can use the freeware Portmon application, as described here:
http://libdivecomputer.org/contribute.html#protocol
Note that in order to capture timestamps, you need to use "File -> Log to File As..." before starting the capture. When using "File -> Save As..." afterwards, it only records the duration of each request, and that's not what we need.
The alternative (on both 32 and 64 bit Windows) is a commercial tool like Eltima. It has a time limited trial version that can do everything we need.
https://www.eltima.com/products/serial-port-monitor/
I looked again at my portmon capture files. Before sending the first read command, the serial port is configured as follows:
2223 0.00000037 IOCTL_SERIAL_GET_BAUD_RATE SUCCESS 2224 0.00000032 IOCTL_SERIAL_GET_LINE_CONTROL SUCCESS 2225 0.00000030 IOCTL_SERIAL_GET_CHARS SUCCESS 2226 0.00000029 IOCTL_SERIAL_GET_HANDFLOW SUCCESS 2227 0.00050920 IOCTL_SERIAL_SET_BAUD_RATE SUCCESS Rate: 115200 2228 0.00143484 IOCTL_SERIAL_SET_RTS SUCCESS 2229 0.00143572 IOCTL_SERIAL_SET_DTR SUCCESS 2230 0.00134276 IOCTL_SERIAL_SET_LINE_CONTROL SUCCESS StopBits: 1 Parity: NONE WordLength: 8 2231 0.00000073 IOCTL_SERIAL_SET_CHAR SUCCESS EOF:0 ERR:0 BRK:0 EVT:0 XON:11 XOFF:13 2232 0.00140348 IOCTL_SERIAL_SET_HANDFLOW SUCCESS Shake:1 Replace:40 XonLimit:64 XoffLimit:64 2233 0.00000077 IOCTL_SERIAL_GET_BAUD_RATE SUCCESS 2234 0.00000048 IOCTL_SERIAL_GET_LINE_CONTROL SUCCESS 2235 0.00000033 IOCTL_SERIAL_GET_CHARS SUCCESS 2236 0.00000033 IOCTL_SERIAL_GET_HANDFLOW SUCCESS 2237 0.00000034 IOCTL_SERIAL_SET_QUEUE_SIZE SUCCESS InSize: 640 OutSize: 640 2238 0.00000039 IOCTL_SERIAL_SET_TIMEOUTS SUCCESS RI:-1 RM:0 RC:0 WM:0 WC:500 2239 0.00000106 IOCTL_SERIAL_GET_COMMSTATUS SUCCESS 2240 0.00053458 IOCTL_SERIAL_CLR_DTR SUCCESS 2241 0.00138172 IOCTL_SERIAL_SET_DTR SUCCESS 2242 0.00030484 IOCTL_SERIAL_CLR_DTR SUCCESS 2243 0.00000128 IOCTL_SERIAL_GET_COMMSTATUS SUCCESS 2244 0.00000221 IOCTL_SERIAL_GET_COMMSTATUS SUCCESS 2245 0.00047142 IRP_MJ_WRITE SUCCESS Length 14: 7B 31 30 30 30 30 30 31 33 39 33 30 36 7D 2246 0.00000090 IRP_MJ_FLUSH_BUFFERS SUCCESS
And then, just before the dump command it reconfigures the port as follows:
2372 0.00000115 IOCTL_SERIAL_PURGE SUCCESS Purge: RXABORT RXCLEAR 2373 0.00000048 IOCTL_SERIAL_GET_COMMSTATUS SUCCESS 2374 0.00000032 IOCTL_SERIAL_GET_BAUD_RATE SUCCESS 2375 0.00000048 IOCTL_SERIAL_GET_LINE_CONTROL SUCCESS 2376 0.00000030 IOCTL_SERIAL_GET_CHARS SUCCESS 2377 0.00000030 IOCTL_SERIAL_GET_HANDFLOW SUCCESS 2378 0.00054569 IOCTL_SERIAL_SET_BAUD_RATE SUCCESS Rate: 115200 2379 0.00126694 IOCTL_SERIAL_SET_RTS SUCCESS 2380 0.00147820 IOCTL_SERIAL_CLR_DTR SUCCESS 2381 0.00145135 IOCTL_SERIAL_SET_LINE_CONTROL SUCCESS StopBits: 1 Parity: NONE WordLength: 8 2382 0.00000065 IOCTL_SERIAL_SET_CHAR SUCCESS EOF:0 ERR:0 BRK:0 EVT:0 XON:11 XOFF:13 2383 0.00277028 IOCTL_SERIAL_SET_HANDFLOW SUCCESS Shake:0 Replace:40 XonLimit:1024 XoffLimit:1024 2384 0.00000075 IOCTL_SERIAL_GET_BAUD_RATE SUCCESS 2385 0.00000047 IOCTL_SERIAL_GET_LINE_CONTROL SUCCESS 2386 0.00000033 IOCTL_SERIAL_GET_CHARS SUCCESS 2387 0.00000033 IOCTL_SERIAL_GET_HANDFLOW SUCCESS 2388 0.00000374 IOCTL_SERIAL_SET_QUEUE_SIZE SUCCESS InSize: 80960 OutSize: 640 2389 0.00000035 IOCTL_SERIAL_SET_TIMEOUTS SUCCESS RI:-1 RM:0 RC:0 WM:0 WC:500 2390 0.00000074 IOCTL_SERIAL_GET_COMMSTATUS SUCCESS 2391 0.00000291 IOCTL_SERIAL_GET_COMMSTATUS SUCCESS 2392 0.00052760 IRP_MJ_WRITE SUCCESS Length 8: 7B 31 32 33 44 42 41 7D 2393 0.00000105 IRP_MJ_FLUSH_BUFFERS SUCCESS
This is almost identical, except for:
The "Shake" setting in the IOCTL_SERIAL_SET_HANDFLOW is different (changes from 1 to 0). This values corresponds to the SERIAL_DTR_CONTROL bit. So that causes the change from SET_RTS to CLR_DTR a few lines earlier. Since DTR was already cleared, this leaves DTR unchanged.
In IOCTL_SERIAL_SET_QUEUE_SIZE, the input queue size changes from 640 to 80960 bytes. This call communicates the recommended buffer size to the underlying driver. Libdivecomputer doesn't do this. The function to configure this existed in the past, but was removed a few years ago. It was windows only anyway. Linux doesn't have such an api, so I doubt this is the problem.
In the first case, the cressi application does the double DTR toggle (CLR_DTR , SET_DTR and CLR_DTR), but not in the second case. So basically the DTR setting doesn't change in the second case.
So nothing really special here. The only missing part for me is the timing info.
BTW, I also remember we had another timing related issue in the past on Linux with FTDI devices. It turned out to be due to different default values for the FTDI low-latency setting. See commit f0faebb3a1ee5ae1cdeffac2cd7afe78a68b46c9 for the details. Maybe this is also relevant here?
Not sure why, but there are two full downloads in there. I also don't know what that last command does.
I tested it and it is a command to force DC to turn off. So computer probably was later reattached, and Cressi software automatically starts download when connection is detected.
Okay, that may be something to look into later.
PS: I'm leaving for a dive trip to Bonaire tomorrow, so I may not be able to answer emails for the next week.
Jef
-
Jef Driesen -
Vsevolod Velichko -
Всеволод Величко