CCD fails to pop up (during development for #722)

[caver456]

Was this error introduced recently? Notice the lack of needsChangeCallsign:

193651:     DATA IS WAITING!!!
193651:      VALID FLEETSYNC DATA!!!
193651:PARSING
193651:☻I110020011002001♥
193651: line:☻I110020011002001♥
193651:FleetSync packetSet: ['10020011002001']
193651:getCallsign called for FleetSync fleet=100 dev=2001
193651:  found matching entry/entries:[['100', '2001', 'Radio 1']]
193651:FleetSync CID detected (not in $PKLSH): fleet=100  dev=2001  callsign=Radio 1
193651:checking for existing open new entry tabs: callsign=Radio 1 continueSec=3600
193651:no other new entry tab was found for this callsign; inside fsParse: calling openNewEntry
193651:openNewEntry called:key=fs callsign=Radio 1 formattedLocString= fleet=100 dev=2001 origLocString= amendFlag=False amendRow=None isMostRecentForCallsign=False
193651:newEntryWidget __init__ called: formattedLocString= fleet=100 dev=2001 origLocString= amendFlag=False amendRow=None isMostRecentForCallsign=False
193651:getCallsign called for FleetSync fleet=100 dev=2001
193651:  found matching entry/entries:[['100', '2001', 'Radio 1']]
193651:newEntryWidget.addTab called: labelText=1936  widget=<__main__.newEntryWidget object at 0x00000227FFF11250>
193651:inserting tab
193651:updating fsLog (fleetsync): fleet=100 dev=2001 callsign=<None>  COM port=COM2
193651:getCallsign called for FleetSync fleet=100 dev=2001
193651:  found matching entry/entries:[['100', '2001', 'Radio 1']]
193652:PARSING
193652:☻I010020011002001♥
193652: line:☻I010020011002001♥
193652:FleetSync packetSet: ['10020011002001']
193652:getCallsign called for FleetSync fleet=100 dev=2001
193652:  found matching entry/entries:[['100', '2001', 'Radio 1']]
193652:FleetSync CID detected (not in $PKLSH): fleet=100  dev=2001  callsign=Radio 1
193652:checking for existing open new entry tabs: callsign=Radio 1 continueSec=3600
193652:checking against existing widget: to_from=FROM team=Radio 1 lastModAge:-1
193652:  new entry widget is already open from this callsign within the 'continue time'; not opening a new one
193652:updating fsLog (fleetsync): fleet=100 dev=2001 callsign=<None>  COM port=COM2
193754:  closing unused new entry widget for Radio 1 due to inactivity
193829:PARSING
193829:☻I110020011002001♥
193829: line:☻I110020011002001♥
193829:FleetSync packetSet: ['10020011002001']
193829:getCallsign called for FleetSync fleet=100 dev=2001
193829:  found matching entry/entries:[['100', '2001', 'Radio 1']]
193829:FleetSync CID detected (not in $PKLSH): fleet=100  dev=2001  callsign=Radio 1
193829:checking for existing open new entry tabs: callsign=Radio 1 continueSec=3600
193829:no other new entry tab was found for this callsign; inside fsParse: calling openNewEntry
193829:openNewEntry called:key=fs callsign=Radio 1 formattedLocString= fleet=100 dev=2001 origLocString= amendFlag=False amendRow=None isMostRecentForCallsign=False
193829:newEntryWidget __init__ called: formattedLocString= fleet=100 dev=2001 origLocString= amendFlag=False amendRow=None isMostRecentForCallsign=False
193829:getCallsign called for FleetSync fleet=100 dev=2001
193829:  found matching entry/entries:[['100', '2001', 'Radio 1']]
193829:newEntryWidget.addTab called: labelText=1938  widget=<__main__.newEntryWidget object at 0x00000227FFB74B90>
193829:inserting tab
193829:updating fsLog (fleetsync): fleet=100 dev=2001 callsign=<None>  COM port=COM2
193830:PARSING
193830:☻I010020011002001♥
193830: line:☻I010020011002001♥
193830:FleetSync packetSet: ['10020011002001']
193830:getCallsign called for FleetSync fleet=100 dev=2001
193830:  found matching entry/entries:[['100', '2001', 'Radio 1']]
193830:FleetSync CID detected (not in $PKLSH): fleet=100  dev=2001  callsign=Radio 1
193830:checking for existing open new entry tabs: callsign=Radio 1 continueSec=3600
193830:checking against existing widget: to_from=FROM team=Radio 1 lastModAge:-1
193830:  new entry widget is already open from this callsign within the 'continue time'; not opening a new one
193830:updating fsLog (fleetsync): fleet=100 dev=2001 callsign=<None>  COM port=COM2

[caver456]

probably best to continue work on #722 then address this afterwards and separately.

[caver456]

during more development work for #722, this has gone from intermittent to consistently failing to spawn CCD.

[caver456]

Probably relevant: when CCD is spawned, it's preceded by the transcript line 'First non-mic-bump call from this device.'

[caver456]

Found the apparent cause - it's a recently introduced bug.

The check to see if it's the "first non-mic-bump call from this device" occurs inside openNewEntry and looks at self.fsLog. But, in fsParse, during development for #722, the first call to fsLogUpdate was moved: it was happening before openNewEntry, but now doesn't happen until after openNewEntry. So, fsLog is blank (or doesn't yet have an entry for the new device) when the first call to openNewEntry happens.

[caver456]

Seems like there are two possible routes to a fix: 1) leave the #722 code as-is: don't make an fsLog entry until after the first call is dealt with; and adjust the 'first-non-mic-bump call' detection logic to also trigger when there is no fsLog entry at all for the given callsign. Since CCD accept does its own call to fsLogUpdate, there should be no case that would lead to repeated 'first-non-mic-bump call' triggers for the same callsign, but, that is something to think about.

2) leave the first-non-mic-bump detection logic as-is (it's already a complex if statement) and add an initial fsLogEntry before the first call to openNewEntry. This could be more 'accurate' and would eliminate the possibility of repeated first-non-mic-bump calls / CCD spawns for the same callsign.

[caver456]

Mostly fixed, but, noticed that having a separate fsLog entry on CCD accept screws with the sequence-checking logic: EOT will attempt a NEW if the previous sequence didn't include BOT- this would be the case for CCD-accept after BOT but before EOT, which means the EOT would attempt a NEW which is self-defeating.

So, probably best to keep the fsLog to just the fsEvents, meaning, don't add an entry on CCD accept.

Instead, it would be nice if 'result' could be 'newEntry+CCD' if a CCD is spawned during the corresponding call to openNewEntry.

[caver456]

Looks like it's safe to create a return value for openNewEntry: normally 'OK' but can be 'CCD'. This can be used to append '+CCD' to the 'result' argument in fsLogUpdate.

Confirmed that there was no existing return value for openNewEntry, and none of the openNewEntry calls have a lvalue - other than 'amendDialog=self.openNewEntry(...' in amendEntry - but, amendDialog is unused. So cleaned up that line to remove the unused lvalue.

[caver456]

Everything above is fixed and QA'ed now, but, something about fsTeamDevices is no longer working, such that tab context menu has no FS/NX entries. Commit as above, but, wait to merge until seeing if this fsTeamDevices issue is related.

[caver456]

yup, it's related. The new callsign, after CCD accept, never appears in fsLog - and fsGetTeamDevices looks for a matching callsign. So, we need to get the callsign into fsLog somehow. Before a few comments ago, this was happening because a new fsLog entry was saved on CCD accept. Getting rid of those fsLogUpdate calls from CCD accept does keep from messing with the sequence logic, but, if the CCD accept entries are needed, maybe a sequence logic change is needed to account for those entries...

[caver456]

Restored the CCD-accept entries, and enhanced fsGetPrevSeq to look backwards through fsFullLog for the previous non-CCD entry.

Everything looks fixed - final QA looks good: