Dive data import error with Hollis DG03

[Rick Walsh]

On 26 March 2014 21:52, Jef Driesen <jef at libdivecomputer.org> wrote:
>
> After seeing this, I think we should leave the 100ms delay and the flush in
> place after all. If the packet fails with a NAK or timeout, then this
> indicates some problem and it's probably a good idea to give the device some
> more time to finish with whatever it was doing.
>
> In the above scenario, if we had waited 100ms after the first NAK, then I
> suspect the second retry will probably have succeeded right away. Our 4ms
> may be sufficient for the normal case, but not when the device tells us
> there was some problem processing the request.
>
> That 100ms delay may also give us an opportunity to use smaller increments
> (e.g. 2ms or even 1ms instead of 4ms) for the dynamic delay. Because on a
> failure, that 100ms delay is what should make the retry work. If the dynamic
> delay is still too small, we'll just get a new error on the next packet.
> This is something that can easily be repeated multiple times, without having
> to worry about exceeding the maximum number of retries.
>
> Can you try once more, with the 100ms and flush added again? And then a
> second try with 1ms increments for the dynamic delay.
>

Ok, so I edited oceanic_atom2.c as I think you wanted and rebuilt.
Tell me if this was wrong. I can read and use a text editor, but I
don't actually know any c.

--- libdivecomputer-delaypatch/src/oceanic_atom2.c    2014-03-26
22:53:57.893512538 +1100
+++ libdivecomputer/src/oceanic_atom2.c    2014-03-26 22:40:20.374732929 +1100
@@ -506,6 +506,9 @@
         device->base.layout = &oceanic_default_layout;
     }

+    // Delay to avoid initial failure
+    serial_sleep (device->port, 100);
+
     *out = (dc_device_t*) device;

     return DC_STATUS_SUCCESS;


When I ran universal, this worked well. There was no error in the
first few reads. First and only error on line 84 of log file.

[0.000057] DATETIME 2014-03-26T11:36:07Z (1395833767)
[0.000097] VERSION 0.5.0-devel (fa90009c293a9ca1a4eaf49a478b381477695c0a)
[0.000125] Opening the device (Oceanic Atom 1.0, /dev/ttyUSB0).
[0.000146] INFO: Open: name=/dev/ttyUSB0
[0.006197] INFO: Configure: baudrate=38400, databits=8, parity=0,
stopbits=1, flowcontrol=0
[0.008177] INFO: Timeout: value=3000
[0.008191] INFO: Sleep: value=100
[0.108326] INFO: Flush: queue=3, input=0, output=0
[0.110220] INFO: Write: size=2, data=8400
[0.112256] INFO: Read: size=1, data=5A
[0.117247] INFO: Read: size=17, data=484F4C4C44473033203142203531324BB3
[0.117296] INFO: Sleep: value=100
[0.217427] Registering the event handler.
[0.217457] Registering the cancellation handler.
[0.217469] Downloading the memory dump.
[0.217576] Event: vendor=484F4C4C44473033203142203531324B
[0.217637] Event: progress 0.00% (0/65536)
[0.220114] INFO: Write: size=4, data=B1000000
[0.221248] INFO: Read: size=1, data=5A
[0.232222] INFO: Read: size=17, data=0516110804110000444D000481006B01CB
[0.232257] Event: progress 0.02% (16/65536)
[0.234187] INFO: Write: size=4, data=B1000100
[0.235234] INFO: Read: size=1, data=5A
[0.246195] INFO: Read: size=17, data=6B01B8061204AE066407A106FF0FAABE7C
...
[0.434241] Event: progress 0.37% (240/65536)
[0.436215] INFO: Write: size=4, data=B1000F00
[0.439634] INFO: Read: size=1, data=5A
[0.447213] INFO: Read: size=17, data=480077A00000280002CD150558825900A3
[0.447224] Event: progress 0.39% (256/65536)
[0.449193] INFO: Write: size=4, data=B1001000
[0.449313] INFO: Read: size=1, data=A5
[0.449319] ERROR: Unexpected answer start byte(s). [in
oceanic_atom2.c:343 (oceanic_atom2_send)]
[0.449326] INFO: Sleep: value=100
[0.549451] INFO: Flush: queue=1, input=0, output=0
[0.549478] INFO: Sleep: value=4
[0.555217] INFO: Write: size=4, data=B1001000
[0.556250] INFO: Read: size=1, data=5A
[0.567225] INFO: Read: size=17, data=49060AA70070470003CD46152707520062
....
[73.284292] Event: progress 99.98% (65520/65536)
[73.284312] INFO: Sleep: value=4
[73.290232] INFO: Write: size=4, data=B10FFF00
[73.291258] INFO: Read: size=1, data=5A
[73.302246] INFO: Read: size=17, data=309026031403001A0E034C0057020000D0
[73.302266] Event: progress 100.00% (65536/65536)
[73.304790] Closing the device.
[73.304806] INFO: Sleep: value=4
[73.311069] INFO: Write: size=4, data=6A05A500
[73.311211] INFO: Read: size=1, data=A5
[73.318235] Result: Success

That's 19 seconds faster than last time

> On Linux:
>>
>> [92.509948] Result: Success


Next I reduced the delays:

--- libdivecomputer-delaypatch/src/oceanic_atom2.c    2014-03-26
22:53:57.893512538 +1100
+++ libdivecomputer/src/oceanic_atom2.c    2014-03-26 22:40:20.374732929 +1100
@@ -369,7 +369,7 @@
         if (nretries++ >= MAXRETRIES)
             return rc;

-        device->delay += 4;
+        device->delay += 1;

         // Delay the next attempt.
         serial_sleep (device->port, 100);
@@ -506,6 +506,9 @@
         device->base.layout = &oceanic_default_layout;
     }

+    // Delay to avoid initial failure
+    serial_sleep (device->port, 50);
+
     *out = (dc_device_t*) device;

     return DC_STATUS_SUCCESS;


Everything sped up a little bit and there were no additional errors.

[0.000041] DATETIME 2014-03-26T11:42:53Z (1395834173)
[0.000079] VERSION 0.5.0-devel (fa90009c293a9ca1a4eaf49a478b381477695c0a)
[0.000106] Opening the device (Oceanic Atom 1.0, /dev/ttyUSB0).
[0.000127] INFO: Open: name=/dev/ttyUSB0
[0.006003] INFO: Configure: baudrate=38400, databits=8, parity=0,
stopbits=1, flowcontrol=0
[0.008015] INFO: Timeout: value=3000
[0.008028] INFO: Sleep: value=100
[0.108163] INFO: Flush: queue=3, input=0, output=0
[0.110052] INFO: Write: size=2, data=8400
[0.112090] INFO: Read: size=1, data=5A
[0.116083] INFO: Read: size=17, data=484F4C4C44473033203142203531324BB3
[0.116132] INFO: Sleep: value=50
[0.166263] Registering the event handler.
[0.166295] Registering the cancellation handler.
[0.166308] Downloading the memory dump.
[0.166418] Event: vendor=484F4C4C44473033203142203531324B
[0.166482] Event: progress 0.00% (0/65536)
[0.168961] INFO: Write: size=4, data=B1000000
[0.169075] INFO: Read: size=1, data=5A
[0.183255] INFO: Read: size=17, data=0516110804110000444D000481006B01CB
...
[0.322075] Event: progress 0.27% (176/65536)
[0.324036] INFO: Write: size=4, data=B1000B00
[0.324056] INFO: Read: size=1, data=A5
[0.324062] ERROR: Unexpected answer start byte(s). [in
oceanic_atom2.c:343 (oceanic_atom2_send)]
[0.324069] INFO: Sleep: value=100
[0.424193] INFO: Flush: queue=1, input=0, output=0
[0.424220] INFO: Sleep: value=1
[0.427055] INFO: Write: size=4, data=B1000B00
[0.428087] INFO: Read: size=1, data=5A
[0.440639] INFO: Read: size=17, data=710171A100105800163E300034114100F6
[0.440660] Event: progress 0.29% (192/65536)
...
[60.986112] Event: progress 99.98% (65520/65536)
[60.986131] INFO: Sleep: value=1
[60.989060] INFO: Write: size=4, data=B10FFF00
[60.990078] INFO: Read: size=1, data=5A
[61.001098] INFO: Read: size=17, data=409026031403001A0E034C0057020000E0
[61.001118] Event: progress 100.00% (65536/65536)
[61.003639] Closing the device.
[61.003656] INFO: Sleep: value=1
[61.006942] INFO: Write: size=4, data=6A05A500
[61.007016] INFO: Read: size=1, data=A5
[61.014034] Result: Success


That's a further gain of 12s. 31s faster than the version before that.


> On Linux:
>>
>> [92.509948] Result: Success
>>
>> On Windows:
>> [67.031023] Result: Success
>
>
> This difference is already smaller than the 32 seconds overhead due to the
> dynamic delay.
>

Rick