Hi everybody, There seems to be some general problems with Suunto dive computer synchronisation.
We got reports so far from the following Suunto computers which use some different libdivecomputer-classes (according to https://github.com/Subsurface-divelog/subsurface/blob/master/descriptor3.tsv): - Suunto Zoop (uses SUUNTO_VYPER): Does not work. After Timeout-Fix: First read returns size=0 - Suunto D4 (uses SUUNTO_D9): App (or Download?) Crashes after about 4 downloaded drives. There should be a mail with logs in the support mail address. - Suunto D4i (uses SUUNTO_D9): Report of working download - Suunto Vyper Air (uses SUUNTO_VYPER2): Gets stuck on "Connecting", might be because of unofficial cable. The "sleep and purge to surpress possible echo" thing seems to be exclusive to the suunto_vyper computers. What I find interesting is that the D4 and D4i (which are using the same driver suunto_d9) have different results. For better debugging I think Jef is right that it would be really nice to have timestamps in the libdc-logs. I attached a possible patch (porting of logfunc from libdivecomputer to libdivecomputer.c), but I'm currently away from my main computer. Maybe somebody could give it a try if it compiles and produces timestamps? With this we can check if the read-function still returns too early for whatever reason. Best regards Christof Am 09.03.20 um 11:19 schrieb Stephen Goodall: > Hi christof, > I'm still getting "failed to receive answer" for the Suunto, Cressi is > still working so the timeout change is good for that one and hasn't > broken it or anything. Is the version below the correct one? > > Suunto: > > Subsurface: v4.9.3-1050-g38ca3f684202, built with libdivecomputer > v0.7.0-devel-Subsurface-NG (0714e327b70bb08f5289c9781c09dc10884881c9) > INFO: Open: transport=1 > INFO: Configure: baudrate=2400, databits=8, parity=1, stopbits=0, > flowcontrol=0 > INFO: Timeout: value=1000 > INFO: DTR: value=1 > INFO: Sleep: value=100 > INFO: Purge: direction=3 > INFO: Sleep: value=500 > INFO: RTS: value=1 > INFO: Write: size=5, data=0500161407 > INFO: Sleep: value=200 > INFO: Purge: direction=1 > INFO: RTS: value=0 > INFO: Read: size=0, data= > ERROR: Failed to receive the answer. [in > /__w/subsurface/subsurface/libdivecomputer/src/suunto_vyper.c:212 > (suunto_vyper_transfer)] > > > Is there any way to get more verbose libdivecomputer logs or something? > > Cheers > > > > On Mon, 9 Mar 2020, 2:26 am Christof Arnosti, <[email protected] > <mailto:[email protected]>> wrote: > > Hi Stephen, > > The build with the improved timeout handling is finished, the > result is at > > https://github.com/Subsurface-divelog/subsurface/suites/506855270/artifacts/2655791 > . Can you test again with your computers? > > Thanks > Christof > > On 08.03.20 15:38, Christof Arnosti wrote: >> >> So I just opened a pull request >> (https://github.com/Subsurface-divelog/subsurface/pull/2656). >> With this the CI will build the updated version and we can test >> again with our computers. The Mares Puck Pro still works as expected. >> >> Best regards >> Christof >> >> On 08.03.20 14:39, Christof Arnosti wrote: >>> >>> Hi Jef, >>> >>> Thanks for your comments. >>> >>> On 08.03.20 09:27, Jef Driesen wrote: >>>> On 8/03/2020 06:31, Dirk Hohndel wrote: >>>>>> On Mar 7, 2020, at 9:17 PM, Stephen Goodall >>>>>> <[email protected] >>>>>> <mailto:[email protected]> >>>>>> <mailto:[email protected]> >>>>>> <mailto:[email protected]>> wrote: >>>>>> Subsurface: v4.9.3-1049-g4529add7053f, built with >>>>>> libdivecomputer v0.7.0-devel-Subsurface-NG >>>>>> (0714e327b70bb08f5289c9781c09dc10884881c9) >>>>>> INFO: Open: transport=1 >>>>>> INFO: Configure: baudrate=2400, databits=8, parity=1, >>>>>> stopbits=0, flowcontrol=0 >>>>>> INFO: Timeout: value=1000 >>>>>> INFO: DTR: value=1 >>>>>> INFO: Sleep: value=100 >>>>>> INFO: Purge: direction=3 >>>>>> INFO: Sleep: value=500 >>>>>> INFO: RTS: value=1 >>>>>> INFO: Write: size=5, data=0500161407 >>>>>> INFO: Sleep: value=200 >>>>>> INFO: Purge: direction=1 >>>>>> INFO: RTS: value=0 >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=0, data= >>>>>> INFO: Read: size=1, data=05 >>>>>> INFO: Read: size=4, data=00161400 >>>>>> INFO: Read: size=3, data=01A01C >>>>>> INFO: Read: size=4, data=00000000 >>>>>> INFO: Read: size=3, data=46B60D >>>>>> INFO: Read: size=4, data=0D004316 >>>>>> INFO: Read: size=3, data=0A1F0A >>>>>> INFO: Read: size=3, data=083B33 >>>>>> Event: model=22 (0x00000016), firmware=10 (0x0000000a), >>>>>> serial=31100859 (0x01da8fbb) >>>>>> INFO: Sleep: value=500 >>>>>> INFO: RTS: value=1 >>>>>> INFO: Write: size=3, data=08A5AD >>>>>> INFO: Sleep: value=200 >>>>>> INFO: Purge: direction=1 >>>>>> INFO: RTS: value=0 >>>>>> INFO: Read: size=0, data= >>>>>> ERROR: Unexpected answer start byte(s). [in >>>>>> /__w/subsurface/subsurface/libdivecomputer/src/suunto_vyper.c:354 >>>>>> (suunto_vyper_read_dive)] >>>>> >>>>> I'm adding Jef to this thread - he's the brains behind >>>>> libdivecomputer and might look at that log and go "oh, this is >>>>> what you are doing wrong"... :-) >>>> >>>> If I look at the above log, then there is indeed something >>>> suspicious. For the first packet, there are several read >>>> attempts returning no data. I'm not sure what is going on here, >>>> but normally libdivecomputer should only do a single request. >>>> Is this something subsurface specific? In the second request, >>>> there is also an empty read returned, and then it fails >>>> immediately, exactly as I would expect. >>>> >>>> I'm not sure if you are aware of this, but for the non-packet >>>> based transports (which includes serial communication), >>>> libdivecomputer expects that the read function returns >>>> DC_STATUS_TIMEOUT for a partial read (e.g. the actual number of >>>> bytes is less than the requested number of bytes). Looking at >>>> the code path that was taking based on the error message, I >>>> think the read function returned DC_STATUS_SUCCESS with 0 bytes >>>> in the actual output parameter. >>> >>> Yes, you are right. Currently it's always returning >>> DC_STATUS_SUCCESS when the underlying implementation does not >>> return an error. >>> >>> The usb-serial-for-android timeout implementation (or rather: >>> the Android USB stack timeout implementation) is buggy, so I >>> always read with a timeout of 0 (infinite). This "works" on my >>> CP210x cable (it's blocking until data is there), but the FTDI >>> driver seems to behave differently and return the bytes in the >>> chips buffer imediately (even if less than requested) instead of >>> waiting. >>> >>> I will rework the gluecode with a while (starttime + timeout < >>> now() && readBuffer.size() < numBytesToRead)-Loop so that this >>> case should be catched as well. Also I will return >>> DC_STATUS_TIMEOUT when there's less bytes to return than >>> requested (but still return the bytes, correct?) >>> >> I even managed to put in the time comparison the correct way >> around ;-) >>> >>>> >>>> Is the timeout respected? Did we return sooner. I can't tell >>>> based on the info in the log because there are no timestamps. >>>> >>>> Another thing that could cause issues for the older Suunto's is >>>> the fact that the protocol is sensitive to timings. That's >>>> because there are several variants of the interface available. >>>> Some of those interfaces do echo the command back, and some >>>> don't. To handle both variants, the suunto_vyper_send() >>>> function waits 200ms (which is long enough for the echo to >>>> appear), then purges the input buffer to discard the echo if >>>> there is one, and then reads the actual response. So if the >>>> Android custom I/O implementation behaves a bit different >>>> timing wise, then this could cause problems. >>> I guess this should work. At least the purge-call is implemented >>> (and clears the readBuffer in application layer as well as calls >>> the purge functionality of the driver), and the >>> sleep-functionality is also implemented. >>>> >>>> For debugging timing related issues, it would be good to have a >>>> timestamp included in the libdivecomputer log, like dctool >>>> does. @Dirk: Can we add this to the subsurface log function? (I >>>> can implement this and send you a patch, but I won't have time >>>> for it today.) >>>> >>>> The RTS line is also required for the Suunto protocol. Is this >>>> implemented correctly? >>> It is implemented. Correctly? I don't know, but I guess so since >>> two of the working computer (Mares Puck Pro / Cressi Leonardo) >>> set the RTS line to the fixed values of 0 or 1 respectively. >>>> >>>> Jef >>> Best regards >>> Christof >
From 4fe91b0545ad897c6c0bc6d67db089c73c92a206 Mon Sep 17 00:00:00 2001 From: Christof Arnosti <[email protected]> Date: Mon, 9 Mar 2020 21:31:28 +0100 Subject: [PATCH] libdivecomputer: add timestamps to log --- core/libdivecomputer.c | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/core/libdivecomputer.c b/core/libdivecomputer.c index 9787ab826..3c96dca5d 100644 --- a/core/libdivecomputer.c +++ b/core/libdivecomputer.c @@ -1195,10 +1195,18 @@ void logfunc(dc_context_t *context, dc_loglevel_t loglevel, const char *file, un FILE *fp = (FILE *)userdata; + dc_usecs_t now = 0; + dc_timer_now (context->timer, &now); + + unsigned long seconds = now / 1000000; + unsigned long microseconds = now % 1000000; + if (loglevel == DC_LOGLEVEL_ERROR || loglevel == DC_LOGLEVEL_WARNING) { - fprintf(fp, "%s: %s [in %s:%d (%s)]\n", loglevels[loglevel], msg, file, line, function); + fprintf(fp, "[%li.%06li] %s: %s [in %s:%d (%s)]\n", + seconds, microseconds, + loglevels[loglevel], msg, file, line, function); } else { - fprintf(fp, "%s: %s\n", loglevels[loglevel], msg); + fprintf(fp, "[%li.%06li] %s: %s\n", seconds, microseconds, loglevels[loglevel], msg); } } -- 2.20.1
_______________________________________________ subsurface mailing list [email protected] http://lists.subsurface-divelog.org/cgi-bin/mailman/listinfo/subsurface
