View Issue Details

IDProjectCategoryView StatusLast Update
0001707Ham Radio DeluxeBugpublic2017-08-05 18:27
ReporterWA9PIE 
Assigned ToK7ZCZ 
PrioritynormalSeveritycrashReproducibilityalways
Status closedResolutionfixed 
Product Version 
Target VersionFixed in Version6.4.0.671 
Summary0001707: Large ADIF import causes Logbook to crash
DescriptionI have a user (osTicket #491667) reports the following:

I get a "Encountered an improper argument." error when importing the attached ADIF file in Logbook.

His ADIF had 60,000 records. If he split it in half, each half imported fine.
Steps To ReproduceImport the attached ADIF into an empty Logbook database.
TagsNo tags attached.
ModuleLogbook
Sub-ModuleData
Testing Not Tested

Relationships

related to 0002158 closedK7ZCZ Trying to Restore a large logfile > 126K contacts gives Improper argument to popup 

Activities

WA9PIE

2014-08-25 11:13

administrator  

AdifFile.zip (883,075 bytes)

WA9PIE

2016-12-04 13:10

administrator   ~0003074

Last edited: 2016-12-04 13:26

View 2 revisions

I did this test myself with a large log. I can confirm that it does generate an error. I'll be attaching a log to this record that has over 125,000 QSOs in it for testing.

It's possible that there was bad data in the guy's log. I'm cleaning up this log and will repeat this.

K7ZCZ

2017-06-07 13:42

manager   ~0003204

I've got a few tweaks in place that are aimed at improving performance for the ADIF import process. There's an incredible amount of N^2 algorithms (searching lists of fields again again, by string name) and some dubious code to delete values from the list view which ends up sending thousands of messages through a loop in Windows.

The investigation also exposes inefficiency in the logbook's storage, which does one memory allocation per cell in the logbook. Since each record has about 240 columns, a 65,000 row logbook import will cause more than 15 million allocations and deletions. During the import process, this issue is exacerbated by the way the lifecycle of CLogbookQSORecordset objects is managed.

In both debug and release builds of the current codebase (after 6.4.650) on my desktop under Visual Studio, I'm able to perform this import without the application crashing.

When I try against a copy of 6.4.649 installed in a VM, the import appears to work successfully then falls over with this message box:


---------------------------
HRD Logbook
---------------------------
Encountered an improper argument.
---------------------------
OK
---------------------------

I'm a bit helpless to debug this; the messgae box offers no information about what call, where in the code, encountered a problem. I think the only way I can proceed is to install some debugging tools into my VM, then get a call stack that shows where this message box occurs. That might give some hints about what is actually going wrong.

Meanwhile, I can check in changes that help with the efficiency a little ...

K7ZCZ

2017-06-09 03:23

manager   ~0003206

After importing a large number of records, the Logbook view will realize it has too many items. It will start removing items in a tight little loop; that loop gets the count of items in the control, see if it's higher than the limit, then deletes an item. Thing is, getting the number of items in the control sends a Windows message to the control, and that's not very efficient.

I've tweaked the code to get the number of items in the control and keep it in a local variable. The loop still sends one message per deletion, but that's absolutely necessary ... and fewer than two messages per deletion.

https://hrdsoftware.visualstudio.com/HRD/_versionControl/changeset/3479

WA9PIE

2017-06-19 23:01

administrator   ~0003223

I think part of this was related to the changes that were made to the WSI... and it was so laborious to update WSI (importing with cluster connection)... every record imported seemed to refresh the entire cluster... but since we buried that code for a while, I don't think this has happened.

Mike - we should chat about this a bit and I can explain it further.

K7ZCZ

2017-07-30 23:30

manager   ~0003790

Turns out this is caused by a data structure that implements the "log file" view in the Logbook. This view contains trace messages that, I presume, are intended to be useful in debugging customer problems. The import process would emit a log file string for each record imported, causing the log file view to decide it wants to prune itself. The code to perform the pruning was broken: it would try to delete a negative number of records, which resulted in the "improper argument" exception. Unfortunately, recent changes to the code caused a locked critical section to leak when the exception was thrown, and that's just a disaster; either more "improper arguments" would appear, or a hang would happen waiting for the orphaned critsec.

I've fixed three things:

1) Fixed the math so the log file data structure correctly prunes itself.

2) Removed a completely unused array involved with the log file view. This saves about 200,000 bytes of memory.

3) Removed the trace message in the first place. It was useless, since there's no way to know which user-visible record it referenced.

There's a couple more improvements which can be made, so I've dropped a couple TODO comments in the cdoe to remind me about them at a future date.

K7ZCZ

2017-07-30 23:31

manager   ~0003791

Fixed with this change set:
https://hrdsoftware.visualstudio.com/HRD/_versionControl/changeset/3710

PD9FER

2017-08-03 10:15

viewer   ~0003866

Confirm Fix in 669

n4kit

2017-08-03 11:36

viewer   ~0003872

I don't have a log file big enough to test, sorry.

g3ucq

2017-08-03 16:18

viewer   ~0003880

Using Mike's log above I had no problems using the Steps to Reproduce. Fixed for me.

WA9PIE

2017-08-05 18:13

administrator   ~0003920

All completed during the 670 build/release.

Issue History

Date Modified Username Field Change
2014-08-25 11:13 WA9PIE New Issue
2014-08-25 11:13 WA9PIE File Added: AdifFile.zip
2014-10-08 22:05 WA9PIE Project 3 - Current Dev List => 2 - Next Dev List (Holding Area)
2015-09-17 13:40 WA9PIE Category Logbook => Bug
2015-09-22 16:37 WA9PIE Fix Build TBD => (select)
2015-09-22 16:37 WA9PIE Report Build 6.2.6.284 => (select)
2015-09-22 16:37 WA9PIE Proposed Release => (select)
2015-09-22 16:37 WA9PIE Summary Bug: Large ADIF import causes Logbook to crash => Large ADIF import causes Logbook to crash
2016-12-04 13:10 WA9PIE Reported in Release 6.2 => 6.3
2016-12-04 13:10 WA9PIE Reported in Build (ie. 377) (select) => 610
2016-12-04 13:10 WA9PIE Note Added: 0003074
2016-12-04 13:10 WA9PIE Assigned To => WA9PIE
2016-12-04 13:10 WA9PIE Status new => confirmed
2016-12-04 13:26 WA9PIE Note Edited: 0003074 View Revisions
2017-03-05 14:21 WA9PIE Assigned To WA9PIE => W4PC
2017-06-07 01:16 K7ZCZ Assigned To W4PC => K7ZCZ
2017-06-07 13:42 K7ZCZ Note Added: 0003204
2017-06-09 03:23 K7ZCZ Note Added: 0003206
2017-06-19 22:58 WA9PIE Project 2 - Next Dev List (Holding Area) => 3 - Current Dev List
2017-06-19 23:01 WA9PIE Note Added: 0003223
2017-07-26 19:31 K7ZCZ Relationship added related to 0002158
2017-07-30 23:30 K7ZCZ Note Added: 0003790
2017-07-30 23:31 K7ZCZ Status confirmed => resolved
2017-07-30 23:31 K7ZCZ Resolution open => fixed
2017-07-30 23:31 K7ZCZ Testing => Not Started
2017-07-30 23:31 K7ZCZ Note Added: 0003791
2017-08-02 07:33 K7ZCZ Fixed in Version => 6.4.0.669
2017-08-03 10:15 PD9FER Note Added: 0003866
2017-08-03 11:36 n4kit Note Added: 0003872
2017-08-03 16:18 g3ucq Note Added: 0003880
2017-08-05 18:07 WA9PIE Testing Not Started => Not Tested
2017-08-05 18:09 WA9PIE Fixed in Version 6.4.0.669 => 6.4.0.670
2017-08-05 18:10 WA9PIE Project 3 - Current Dev List => Ham Radio Deluxe
2017-08-05 18:13 WA9PIE Note Added: 0003920
2017-08-05 18:13 WA9PIE Status resolved => closed
2017-08-05 18:27 WA9PIE Fixed in Version 6.4.0.670 => 6.4.0.671