View Issue Details
|ID||Project||Category||View Status||Date Submitted||Last Update|
|0002872||Ham Radio Deluxe||Bug||public||2018-09-02 02:47||2018-09-11 13:18|
|Platform||PC||OS||Windows Pro 10||OS Version||1803 64-bit|
|Target Version||Fixed in Version||188.8.131.526|
|Summary||0002872: QSO Forwarding Packets Sent by Logbook Have Invalid QSO Date|
|Description||When an N1MM Section 5 Contact Info datagram is sent by the QSO Forwarding feature in Logbook, the <TimeStamp> field is meant to contain a value that represents the QSO Date and Time On values for a contact. However, the date portion of the timestamp value is always set to '1899-12-30' which is believed to be the null or unknown date value used in Logbook.|
|Steps To Reproduce||1. Make sure that Logbook has the Forward logbook changes using UDP checkbox enabled in the UDP Send group in the QSO Forwarding settings;|
2. Make sure the Send Address and Send Port values are set to appropriate values (e.g. localhost and 5000);
3. Using a protocol analyser start a capture of UDP packets broadcast by hrdlogbook.exe;
4. Create a new QSO record in Logbook using the Add Log Entry window;
5. Click on the Add pushbutton to close ALE window and add the contact to the Logbook database;
6. The protocol analyser should capture a UDP datagram containing a N1MM Section 5 Contact Info packet representing the contact logged;
7. Notice that the date portion of the timestamp value is set to '1899-12-30', and not the QSO Date value of the contact.
|Additional Information||Attached is a screen capture of the UDP packet captured showing the incorrect date value.|
|Tags||No tags attached.|
Timestamp Defect.jpg (134,865 bytes)
Timestamp Defect.jpg (134,865 bytes)
Thanks for opening an individual bug, Chris; it makes tracking so much easier. And thanks for the detailed repro steps.
This is looking like a localization issue. Can you please tell me what your date and time format settings are, and which locale you've got set in Windows?
Also at my site:
Signal reports are not being transferred.
Frequency is not being transferred, nor Frequency RX. JT Alert sends both.
Band incorrectly show 9m in list display for a 30m contact.
End time defaults to 00:00:00
My Station info is not populated.
Power is not transferred.
No problem Mike, I am happy to help.
English (Australia) is my locale and Short Date format is d/MM/yyyy Dates in the Logbook UI conform to that format.
Short Date Format.jpg (42,238 bytes)
Short Date Format.jpg (42,238 bytes)
||My comments actually relate to QSOs sent into Logbook rather than from Logbook, just to clarify. Thanks to Chris for pointing out that this ticket is for the other direction.|
Thanks, Chris. Just to confirm, "d/MM/yyyy" has a little dee, so that means a day number with no leading zeroes, right? Your example date of "9/07/2018" means the 9th day of 7th month in 2018, amirite?
There are lots of bugs in the logbook with inconsistent date representation, so this will actually be a pretty tough fix.
||Correct - 9/07/2018 is the 9th July 2018 for us upside down 'downunder'.|
I'm sorry, Chris, but Iv'e spent about six hours on it and I can't get this issue to repro.
I've set my system to use "English (Australia)" date and time formats, and I've entered any date I can think of into the ALE. The resulting send from the UDP forwarder has a correct date in all cases.
I'm compelled to make a strategic fix; there are lots of places in the logbook code where date handling is bogus, and I can't fix them all -- right now, anyway; it's a big effort that will require a lot of testing. So I want to find this specific problem and nail it down. The UDP code is called with a normalized ISO-9001 date (like "20180709") which is then parsed correctly and formatted the right way before it's made part of the UDP packet and sent off.
Are there any other hints you can provide?
Yes... I can still reproduce this, but using a slightly different way than using the steps to reproduce that I provided.
My alternate method of reproduction is using my testing utility that sends an N1MM Section 5 contact to the Receive side of QSO Forwarding in Logbook, and captures what Logbook re-broadcasts on the Send side, and this is where I get the 1899 year value.
Here are my results:
Using ALE with the current time and date UTC, Logbook broadcasts <timestamp>2018-06-09 03:28:33</timestamp> which is incorrect. The correct local system time UTC gets logged in Logbook, but the UDP datagram has the ISO date month and day reversed - a locale issue?
UDP Datagram Loopback Method
If I send a contact with my test utility to Logbook containing <timestamp>2018-06-30 23:59:59</timestamp> (30th June), the correct date and time is logged in Logbook, but the UDP datagram broadcasts <timestamp>1899-12-30 23:59:59</timestamp>. A bad or null date, but time is correct.
I do apologize for assuming the steps to reproduce that I provided would produce identical results to the actual method I use. I hope I haven't sent you on a wild goose chase, and I will be careful to avoid that in the future!
However, it would appear as though there may be two defects:
(1) An N1MM Section 5 contact received by Logbook is correctly inserted in logbook, but it appears to 'loose' the date if re-broadcast;
(2) A contact added by ALE is correctly inserted in Logbook, but the month and day are reversed in the ISO date if broadcast - perhaps only for English (Australian) and other d/MM/yyyy type locales.
||I hasten to add that today's date being 6th of Sept. can be easily misread when displayed as 6/09/2018 or 9/06/2018 depending upon locale - caught me out today.|
I hasten to add that today's date being 6th of Sept. can be easily misread when displayed as 6/09/2018 or 9/06/2018 depending upon locale - caught me out today.
ALE and Remote Inserts.pdf (150,103 bytes)
||Another cut 'n' paste error on my part - is there anyway to edit notes? I meant to say: refer to attachment for protocol analyzer captures.|
I think you'll find that #1 is fixed in builds 881 and newer. (If it's not, please let me know -- I can't cause it to happen, and I think the resolution was the same as 2871).
#2 is the bug we're looking for, and I can see where it happens. As I feared, it's not an easy fix. The logbook handles dates just be storing strings, so there's no normalization in the representation. Even if I make a fix as strategically as possible, there's a chance that I break something else, so I have to try to find a way to isolate the desired fix. (Or, go the other way, and fix everything about date handling in the logbook. I'm not sure that the timing is right for that just now.)
#2 is reproduced by adding a contact via ALE, whereas #1 is reproduced by sending a datagram to Logbook to add the contact, and it still there in 822.
Refer to my ALE and Remote Inserts.pdf attachment a couple of posts back - packet 2 in that document is the datagram sent to Logbook on port 12060 with a date of 2018-06-30, and Packet 3 is the datagram sent in response by Logbook on port 5000 where the date gets 'lost' and sent as 1899-12-30.
Packet 1 in that document is #2, i.e. the datagram sent after adding a contact via ALE.
I've found a surgical fix for #2, which I've checked in here to resolve this issue.
Just tested #2 with 823, and the correct ISO date is now being sent in QSO Forwarding datagram, the 'lost' date and 'found' its way to Logbook instead.
#2 UDP Pass.jpg (107,271 bytes)
#2 UDP Pass.jpg (107,271 bytes)
#2 Logbook Fail.jpg (70,693 bytes)
#2 Logbook Fail.jpg (70,693 bytes)
||Another typo on my part - I meant to say Just "just tested #2 with 883.."|
Retested with 884:
#1: Fixed - Contact added with ALE logs corrects values, and correct time and date in the datagram sent in response by Logbook on port 5000.
#2: Fail - Test datagram sent to Logbook on port 12060 with a timestamp value of 2018-06-30 23:59:59, but the datagram sent in response by Logbook on port 5000 contains the timestamp value of 2018-06-30 23:59:59. It looks like the time portion is getting lost now.
#1 Logbook Pass.jpg (67,922 bytes)
#1 Logbook Pass.jpg (67,922 bytes)QSO Forwarding (N1MM) Test Results 884 beta.pdf (158,833 bytes)
CORRECTION: #2: Fail - Test datagram sent to Logbook on port 12060 with a timestamp value of 2018-06-30 23:59:59, but the datagram sent in response by Logbook on port 5000 contains the timestamp value of 2018-06-30 00:00:00. It looks like the time portion is getting lost now.
Yet another typo on my part - just as well I can edit posts in the Beta Forum and Facebook, but I get into trouble in Mantis :)
Sorry, but I'm super-confused. Y ousay that you tested with 823, but there's no build numbered 823. In that build, you say something about a "lost" date that was "found", and I don't understand what you specifically mean.
Then you say you've tested with 884 and say "fail", but your description of that failure doesn't make sense to me. You say that the timestamp is a certain value, and that the resulting value output is the same as the input value. Was it somehow supposed to be something else?
It sounds like something broken between 884 and some other build, but I don't know when it was working because we've ont shipped a build numbered 823. And it's not perfectly clear to me what might have broken.
I'm working several issues -- there's a lot going on, and not much time left to do it. I'm sorry if you think I'm being overyly precise or difficult, but I just can't figure out what it is you're trying to report. It might be best to reset to explaining the repro steps you're performing, writing up what you observe, and explaining what you expected to see. Please focuse on clarity and correctness in your descriptions ... otherwise, there's just too much doubt in trying to understand what might be wrong and what needs to be fixed.
Sorry Mike, there are several typos in my note 0006147 above. I meant to type 883 instead of repeatedly typing 823.
I added another note 0006149 explaining the typo with the timestamp value because I see no way of editing notes.
I did include an attachment called ‘QSO Forwarding (N1MM) Test Results 884 beta.pdf’ to note 0006147 which clearly documents the issue using analyser captures and highlighting.
I do understand that time is running out, which is why I have spent the time I have testing 882, 883 and 884 in the last few days, and my attention to detail has waived a bit.
So, steps to reproduce:
1. Make sure UDP Send is enabled on a suitable port;
2. Make sure UDP Receive is enabled for QSL5 type datagrams on a suitable port;
3. Refer to page 2 of ‘QSO Forwarding (N1MM) Test Results 884 beta.pdf’ attachment for the QSO Forwarding settings used in my test case;
4. Send a QSL5 datagram to Logbook which should result in a row being inserted in Logbook and QSL5 datagram being sent;
5. Check the row inserted in Logbook for the correct QSO Date and Time On values - they are correct in my test case;
6. Check the timestamp value in the datagram sent is the same value as received - the time portion set to 00:00:00 is incorrect (or “lost”).
When a row is added to Logbook via ALE, DM-780, Logbook API (TCP:7826), or QSL9 UDP Receive (UDP:2333), the row inserted has the correct QSO Date and Time values, and the QSL5 datagram sent has the correct timestamp as well. These are the most likely ways that users will log contacts.
It is only when a row is added via QSL5 UDP Receive (N1MM, UDP:12060) that the time portion of the timestamp sent is incorrect. This may be an unlikely use in practice, so maybe this can be deferred if time runs out.
Because this issue initially involved an incorrect date, but now it is time that is wrong, I think that is what I meant about “lost” and “found”. Re-reading now what I typed, it doesn’t make sense to me either.
||Thanks, Chris. I'm watching this one.|
||Unable to test|
||Putting FIV back... I changed it by accident.|
||Great, thanks for the clarification, Chris. The clearer things are, the lst time I have to spend guessing and the better chance I have of making a good fix on the first try.|
Fixed with this checkin
I logged contacts using Logbook API (TCP:7826), DM-780, ALE, UDP:2333 (QSL9) and UDP:12060 (QSL5) and the timestamp in all five QSL5 datagrams sent on UDP:5000 are correct.
|2018-09-02 02:47||vk2byi||New Issue|
|2018-09-02 02:47||vk2byi||File Added: Timestamp Defect.jpg|
|2018-09-02 09:28||K7ZCZ||Note Added: 0006052|
|2018-09-02 13:04||k2ie||Note Added: 0006053|
|2018-09-02 17:20||vk2byi||File Added: Short Date Format.jpg|
|2018-09-02 17:20||vk2byi||Note Added: 0006056|
|2018-09-02 22:12||k2ie||Note Added: 0006061|
|2018-09-02 23:49||K7ZCZ||Note Added: 0006063|
|2018-09-02 23:50||K7ZCZ||Relationship added||related to 0002798|
|2018-09-03 01:14||vk2byi||Note Added: 0006065|
|2018-09-05 22:12||K7ZCZ||Note Added: 0006091|
|2018-09-05 23:51||vk2byi||Note Added: 0006092|
|2018-09-05 23:55||vk2byi||Note Added: 0006093|
|2018-09-06 01:38||vk2byi||File Added: ALE and Remote Inserts.pdf|
|2018-09-06 01:38||vk2byi||Note Added: 0006094|
|2018-09-06 01:41||vk2byi||Note Added: 0006095|
|2018-09-07 19:11||K7ZCZ||Note Added: 0006127|
|2018-09-07 20:39||vk2byi||Note Added: 0006128|
|2018-09-07 22:41||K7ZCZ||Assigned To||=> K7ZCZ|
|2018-09-07 22:41||K7ZCZ||Status||new => resolved|
|2018-09-07 22:41||K7ZCZ||Resolution||open => fixed|
|2018-09-07 22:41||K7ZCZ||Testing||=> Not Started|
|2018-09-07 22:41||K7ZCZ||Note Added: 0006129|
|2018-09-08 02:32||vk2byi||File Added: #2 UDP Pass.jpg|
|2018-09-08 02:32||vk2byi||File Added: #2 Logbook Fail.jpg|
|2018-09-08 02:32||vk2byi||Note Added: 0006134|
|2018-09-08 06:40||vk2byi||Note Added: 0006137|
|2018-09-08 09:45||K7ZCZ||Project||1 - Backlog => 3 - Current Dev List|
|2018-09-08 09:45||K7ZCZ||Fixed in Version||=> 184.108.40.2063|
|2018-09-08 13:52||K7ZCZ||Relationship added||related to 0002884|
|2018-09-08 22:27||vk2byi||File Added: #1 Logbook Pass.jpg|
|2018-09-08 22:27||vk2byi||File Added: QSO Forwarding (N1MM) Test Results 884 beta.pdf|
|2018-09-08 22:27||vk2byi||Note Added: 0006147|
|2018-09-08 22:55||vk2byi||Note Added: 0006149|
|2018-09-09 13:43||K7ZCZ||Note Added: 0006155|
|2018-09-09 19:10||vk2byi||Note Added: 0006158|
|2018-09-09 20:17||WA9PIE||Note Added: 0006159|
|2018-09-10 02:42||g3ucq||Note Added: 0006166|
|2018-09-10 11:01||WA9PIE||Fixed in Version||220.127.116.113 =>|
|2018-09-10 11:04||WA9PIE||Fixed in Version||=> 18.104.22.1683|
|2018-09-10 11:04||WA9PIE||Note Added: 0006178|
|2018-09-10 11:30||K7ZCZ||Note Added: 0006183|
|2018-09-10 11:31||K7ZCZ||Note Added: 0006184|
|2018-09-10 19:28||vk2byi||Note Added: 0006196|
|2018-09-10 20:29||WA9PIE||Status||resolved => closed|
|2018-09-10 20:29||WA9PIE||Fixed in Version||22.214.171.1243 => 126.96.36.1995|
|2018-09-10 20:29||WA9PIE||Testing||Not Started => Beta Successful|
|2018-09-11 13:15||WA9PIE||Project||3 - Current Dev List => Ham Radio Deluxe|
|2018-09-11 13:18||WA9PIE||Fixed in Version||188.8.131.525 => 184.108.40.2066|