blank new entry window

[caver456]

(on 3.0.1b in R5)

[caver456]

the prior most recent entry in the log was 0921, from 409, clue 22

Highlights from the log file, beginning with the start of the 0921 409 clue22 entry:

092149 - CID and openNewEntry from 409 (100:3156) 092154 - CID+GPS from 3156; continue time handled (no new dialog); locator request sent with 200 response 092200 - CID 3156; continue time handled (no new dialog) 092200 - automatic new entry saved 'LOCATED A CLUE' - radio operator is gathering details' 092209 - CID+GPS from 3156; continue time handled (no new dialog); locator request sent with 200 response 092215 - CID and openNewEntry from KW-100-3011, and 'setting needsChangeCallsign' 092219 - openChangeCallsignDialog called for 3011 092344 - CID 3156; continue time handled (no new dialog) 092348 - CID+GPS from 3156; continue time handled (no new dialog); locator request sent but timed out 092354 - CID 3156; continue time handled (no new dialog) 092401 - CID+GPS from 3156; continue time handled (no new dialog); locator request sent but timed out 092403 - CID 3156; continue time handled (no new dialog) 092406 - CID 3156; continue time handled (no new dialog) 092407 - CID+GPS from 3156; continue time handled (no new dialog); locator request sent with 200 response 092415 - CID 3156; continue time handled (no new dialog) 092416 - CID 3156; continue time handled (no new dialog) 092417 - CID+GPS from 3156; continue time handled (no new dialog); locator request sent with 200 response 092428 - clue report pdf generated, copied to Z:\, closed; new entry created with clue#22; logs saved

Looks like the blank window probably came up 25 seconds after the save, and nothing else happened for the next 6+ minutes:

092428:  done writing Z:\\Bridgeport_2022_09_24_081953_clueLog.csv
092453:openNewEntry called:key=False callsign=None formattedLocString=None fleet=None dev=None origLocString=None amendFlag=False amendRow=None
093136:PARSING
....

Notes and questions from these highlights:

• intervening mic bump (?) from 3011 - only one CID in this timeframe - should get a timeline of 3011
• why the 4-second delay before openChangeCallsignDialog before 092219?
• timed out locator requests 092348 and 092401
• back-to-back BOT (CID only) from 3156 at 092403, 092406, and again 092415, 092416 - the first had no EOT, the second had a EOT 1 sec later
• the openNewEntry at 092453 is what happens when you click the Add Entry button on the main window, but, it opens with a NED inside it (though there is no log file output to indicate this fact)

[caver456]

092215 is the only mention of '3011' in the entire log file. So just a CID, no second CID which would indicate EOT even without GPS. 3011 is SAR11, apparently it was an unintentional mic bump because SAR11 was ops chief.

[caver456]

Couldn't reproduce locally, trying to match the timeline as much as possible. Might find out some more info from the reporting party, but, otherwise the best hope is to add some additional logging. Having trouble uploading the log files to google drive in order to share here.

[caver456]

Was able to reproduce the problem (blank NEW with no obvious way to close it) - here's the full log of the test case - next step is to analyze it further and try to reproduce with a smaller test case.

Since the log file doesn't record all actions, here's an attempt to recount the timeline from memory:

1. call from 3011; change callsign pops up; set to 'Team 101'
2. in NED, click 'LOCATED A CLUE'
3. call from 3021, resulting in a second tab on the stack, but the first tab on the stack keeps focus as expected (changeCallsignDialog doesn't pop up until its stack tab has focus)
4. click the newest stack tab so that its changeCallsignDialog opens
5. set to callsign Team 302
6. click the oldest / first stack tab
7. cancel the clue form
8. wait a minute or more
9. newest tab auto-closes, then fairly soon after, oldest tab auto-closes
10. NEW drops to background but still exists as in the pic

[caver456]

Highlights from the log file above:

060402 - CID 3011; NED opened; change callsign dialog opened 060407 - callsign set to Team 101 060410 - newEntry: 'LOCATED A CLUE' button pressed 060420 - CID 3021; NED opened (on stack), with 'setting needsChangeCallsign' (but focus stays with first tab on stack) 060556 - change callsign dialog opened for 3021 (when its stack tab was clicked) 060601 - callsign set to Team 123 060717 - cancel clue dialog (and automatic newEntry created)

No other useful entries in the log file. The automatic closings of the NEDs don't create log file entries.

This jives with the event timeline from memory in the previous comment.

[caver456]

Duplicated the problem again by using the same steps. Adding some details to the above:

• after setting the second team (060601 above), leave that new stack tab with focus
• leaving it sit as described (clue dialog open; focus on more recent stack tab; nothing typed into any NED or into the clue dialog) does NOT result in either NED closing after 60 sec
• then, cancel (and confirm cancellation of) the clue dialog: the new stack tab keeps focus, and after 60 sec one NED closes, then soon the other closes, and the NEW is left empty and pushed to the background, but remains open

[caver456]

Hopefully this can be addressed by simply closing the NEW when the last stack tab / last NED closes due to auto-cleanup.

This also points out that the auto-close may not be working exactly as expected. Should temporarily add some code to log the auto-close timer for each NED.

[caver456]

Changing priority to medium because this blank window doesn't actually prevent any normal behavior - it just looks goofy. The next time a NED is spawned, the NEW resumes behavior as before and closes when the last NED closes.

[caver456]

Notes:

• with a simple auto-cleanup of just one team, the NEW actually closes successfully - so it's probably not a race condition issue
• after CCD (changeCallsignDialog) accept for second team, lastModAge remains frozen for both teams, until the clue dialog is canceled. This is probably a separate issue.
• the code to lower the window gets called in all cases - but why does it close in some cases but stay open in these problem cases?
• NEW remains open but blank and lowered after both NEDs close, even if the second closure was several seconds after the first closure:

064006:lastModAge:-1
064007:lastModAge:4
064007:lastModAge:-1
064008:lastModAge:4
064008:lastModAge:-1
064009:newEntry called with these values:
064009:['0638', 'FROM', 'Team 101', "RADIO LOG SOFTWARE: radio operator has canceled the 'LOCATED A CLUE' form", '', '', 1664285919.534073, '100', '3024', '']
064009:  writing C:\Users\caver\Documents\New_Incident_2022_09_27_063549.csv
064009:  done writing C:\Users\caver\Documents\New_Incident_2022_09_27_063549.csv
064009:  writing C:\Users\caver\Documents\New_Incident_2022_09_27_063549_clueLog.csv
064009:  done writing C:\Users\caver\Documents\New_Incident_2022_09_27_063549_clueLog.csv
064009:lastModAge:4
064009:lastModAge:-1
064010:lastModAge:5
064010:lastModAge:0
064011:lastModAge:6
064011:lastModAge:1
064012:lastModAge:7
064012:lastModAge:2
064013:lastModAge:8
064013:lastModAge:3
064014:lastModAge:9
064014:lastModAge:4
064015:lastModAge:10
064015:lastModAge:5
064016:lastModAge:11
064016:  closing NED
064016:newEntryWidget.closeEvent t3
064016:removeTab called: caller=<__main__.newEntryWidget object at 0x078A82B0>
064016:  tab count before removal:4
064017:lastModAge:7
064018:lastModAge:8
064019:lastModAge:9
064020:lastModAge:10
064021:lastModAge:11
064021:  closing NED
064021:newEntryWidget.closeEvent t3
064021:removeTab called: caller=<__main__.newEntryWidget object at 0x078B0F10>
064021:  tab count before removal:3
064021:lowering: count=3

[caver456]

The real fix was just to change .lower() to .hide() in newEntryWindow.autoCleanup().

.lower() just places the window at the bottom of the display stack, but, leaves it displayed, and it still shows up in the sub-window display list when you hover over the running python taskbar icon in the Windows taskbar.

.hide() removes it from the display and removes it from the sub-windows display list, but, does not destroy it - so raise() in the future still works the same way.

Why was it .lower()? Probably just confusion over what .lower() does. So, changing to .hide() probably matches the original intent.