NIL if ghosted before logging

[scotthibbs]

Description

In any contest, if you get the call correct and then don't follow up with the exchange with "TU" before the sender ghosts, there is no credit for the log entry.

To duplicate, copy a call sign correctly (single call works easy for this). Receive an "R" with exchange. Place the exchange in the fields but don't hit enter. After several tries the sender ghosts. When you hit enter to send "TU" the log displays "NIL"..

However, this should count for several reasons. One, you wouldn't know in the real world they tuned away, only that they just stopped sending. And two, they have your contact in their log and when you turned in this contact it would be counted. And it should be counted if correct. Three, at least the call should be correct even if the exchange is wrong.

Steps To Reproduce

To duplicate, copy a call sign correctly (single call works easy for this). Receive an "R" with exchange. Place the exchange in the fields but don't hit enter. After several tries the sender ghosts. When you hit enter to send "TU" the log displays "NIL"..

Expected behavior

The error shouldn't be "NIL" but an exchange error. The user should know if it is correct and counted or incorrect for the exchange. The user knows the call is correct but it just states "NIL" without giving feedback on the exchange.

Actual Behavior

"NIL" error when call is known to be correct.

Reproduces how often

100%

Version information

• Morse Runner version: [e.g. 1.68] 1.82 and previous
• OS/Version: [e.g. Windows 10] Win10

Additional context

Tasks

Please let us know if you are available to help. (replace '[ ]' with '[x]' to affirm)

• Yes, I'm available to help test a solution to this problem.
• coding
• code review and merge to main
• release notes
• testing

[w7sst]

Summary

Well, this was an interesting bug to fix. I learned a lot, including "be sure to read the bug before starting to fix it." I ended up solving the root cause of the problem before coming back to read the original bug report. Lesson learned.

The information below attempts to summarize the changes made in the code. The state machines are hard to get your head around, but I did find that these state diagrams helped me think through and identify the problem. I tried several different ways to document these state changes and found the diagrams were the easiest to comprehend.

An engineering build of these changes are available here

Four commits

There are four commits for this fix:

1. Add comments to existing code, DxOperator, TOperatorState
   Added some code comments while studying the problem.

2. Fix caller ghosting after entering call and exchange info (root cause 1)

    This is the first of three parts to fix the ghosting issue.
    Here, one of the root causes of caller ghosting is when the
    DxOperator.Patience value was not increased after receiving
    the last transmission from user. Thus, it would timeout sooner
    than expected. To fix this problem, the Patience value increased
    by calling TDxOperator.MorePatience. This is basically saying
    that when the DxOperator receives a transmission from the User,
    they will continue to work the QSO without loosing patience
    and giving up - thus the notion of "more patience" in introduced.

3. Fix ghosting by stations leaving the QSO early after calling them (root cause 2)

    This is the second of three parts to fix the ghosting issue.
    This fix addresses the second root cause of caller ghosting
    where a Dx station would disappear almost immediately after
    being created. This would occur about 10% of the time. The user
    would enter and send the Dx station's callsign, only to discover
    that the station goes silent and does not return its exchange information.
    
    The root cause for this second problem was traced back to a call to the
    random function RndRayleigh(4). The result of this call is used to set
    the value of DxOperator.Patience. Patience represents operator patience,
    an expression of how patient the Dx operator will be while waiting for
    a responce from the user. RndRayleigh(4) will return a random integer
    value with a Mean of 4. The problem is, 11% of the time, this value
    could be 0 or 1. Given a value of 0 or 1, other logic will cause the
    DxStation would disappear almost immediately. This was fixed by replacing
    the RndRayleight(4) call with '2 + RndRayleigh(3)'. This change makes sure
    that a minimum value of 2 is returned. The new Mean is now 5 instead of 4.

4. Fix problem where ghosted calls are not added to log (the original bug)

    This is the third of three changes addressing the issue of
    caller ghosting. A ghosted call was originally handled as
    a failed QSO after the Dx Station timeout out due to User
    inactivity. Once failed, it was deleted from the simulation
    before the QSO was logged by the user. With this fix, DxStation
    will stop sending and remaining in the set of active stations.
    This allows the QSO to be logged as usual by the user.

Detailed Discussion

Anatomy of a Typical QSO

Let's start by looking at the flow of a typical QSO within MorseRunner.

• A typical QSO will have no errors or retries.
• The state machine below shows the state machine transitions during a typical QSO.
• Each state is from the perspective of the DxOperator within the simulation.

---
title: Basic Flow of a Typical QSO
---
stateDiagram-v2
  [*] --> osNeedPrevEnd
  osNeedPrevEnd --> osNeedQso: msgCQ
  osNeedPrevEnd --> osNeedQso: msgTU
  state IsMyCall <<choice>>
  osNeedQso --> IsMyCall: msgHisCall
  IsMyCall --> osNeedNr: IsMyCall=Yes
  IsMyCall --> osNeedPrevEnd: IsMyCall=No
  osNeedNr --> osNeedEnd: msgNR
  osNeedEnd --> osDone: msgTU
  osDone --> [*]

%%  IsMyCall --> osNeedCallNr: IsMyCall=Almost
%%  osNeedCallNr  --> osNeedNr:  IsMyCall=Yes

Notes

• There are five basic states in this QSO.
• These states should be viewed from the perspective of the remote Dx Station operator.

osNeedPrevEnd

• The operator is waiting for the previous QSO to end. In other words, this DxStation is wating for the user's current QSO to end.
• It will end when the user sends either TU or a new CQ.

osNeedQso

• The Dx operator has received the TU or CQ from the user. It will start sending it's callsign and wait to hear the user call them back.
• Every 5 seconds or so, the Dx Station will repeat sending its callsign.
• A QSO is started once the Dx Station has received its callsign.
• If their callsign is not heard, it will repeat until the user calls them or until the user starts a QSO with a different station.
• If the DxStation doesn't hear its callsign, it will timeout after resending its callsign several times. This retry period is determined by Operator Patience ('DxOperator.Patience`).
• See additional discussion under Patience.

osNeedNr

• The Dx operator has heard their callsign and is now waiting to hear the user's exchange (aka NR).
• If the user's exchange is not heard, the DxStation will repeat its own signal report to the user.

osNeedEnd

• The Dx operator is waiting for the user to send 'TU', thus marking the end of the QSO. Once 'TU' is received, the state moves to osDone.

osDone

• The 'TU' message has been received and the user is moving onto the next QSO.
• This QSO is now complete and can be logged.
• Once logged, this DxStation will be deleted.

How does Call Ghosting Occur?

This next diagram shows the remaining operator states and messages occurring in most QSOs. It can look complicated, but focus on one state at a time and look at the messages/events leaving each state.

Caller Ghosting will occur whenever the DxOperator.Patience value decrements to zero. This is occurring on most of the msgNR messages. Some of these messages will change the state, but they also implicitly allow the Patience value to be decremented. When Patience=0, the caller will disappear and ghost the QSO. These messages are identified with an asterisk *.
I was able to see these once I started creating the diagrams. Look for the msgNR* messages below. Operationally, these will occur when the user is trying to copy the correct exchange from the DxStation and sends his report to the DxStation.

Here is a state diagram showing the typical flow of a QSO.

• Each state is from the perspective of the DxOperator.
• Messages represent the message being sent from the user.
• Each DxStation will react according to the logic in this state machine.
• A '*' identifies those messages that do not reset the DxOperator.Patience value to 5. Normally when a State change is made, the DxOperator.Patience value is reset to 5, indicating 5 retry opportunities. The DxStation will send its response up to 5 times without hearing from the user. Once the DxOperator's patience wears thin (by going to zero), the DxStation will go away.
• Not setting the DxOperator.Patience value can lead to caller ghosting. Caller ghosting can occur when the Patience count goes to zero and the DxStation goes away and leaves the QSO.

---
title: Basic Flow of a Typical QSO (v1.84 and prior)
---
stateDiagram-v2
  [*] --> osNeedPrevEnd

%% msgCQ - DxOperator receives CQ from the User
%%  osNeedPrevEnd --> osNeedQso: msgCQ, P=[0,15]
  osNeedPrevEnd --> osNeedQso: msgCQ
%%  osNeedQso     --> osNeedQso: msgCQ*
  osNeedEnd     --> osDone:    msgCQ
%%  osNeedNr      --> osFailed:  msgCQ
%%  osNeedCall    --> osFailed:  msgCQ
%%  osNeedCallNr  --> osFailed:  msgCQ

%% IsMyCall=Yes - DxOperator receives his callsign from the user with an exact match
  osNeedPrevEnd --> osNeedNr:  IsMyCall=Yes
  osNeedQso     --> osNeedNr:  IsMyCall=Yes
  osNeedCallNr  --> osNeedNr:  IsMyCall=Yes
  osNeedCall    --> osNeedEnd: IsMyCall=Yes

%% IsMyCall=Almost - DxOperator receives a partial match of his callsign from the user
  osNeedPrevEnd --> osNeedCallNr: IsMyCall=Almost
  osNeedQso     --> osNeedCallNr: IsMyCall=Almost
  osNeedNr      --> osNeedCallNr: IsMyCall=Almost
  osNeedEnd     --> osNeedCall:   IsMyCall=Almost

%% IsMyCall=No - DxOperator receives a callsign from the user that does not match his callsign
  osNeedQso     --> osNeedPrevEnd: IsMyCall=No
%%  osNeedNr      --> osFailed:      IsMyCall=No
%%  osNeedCall    --> osFailed:      IsMyCall=No
%%  osNeedCallNr  --> osFailed:      IsMyCall=No
  osNeedEnd     --> osDone:        IsMyCall=No

%% msgNR - DxOperator receives exchange (NR) from the User
  osNeedQso     --> osNeedPrevEnd: msgNR
  osNeedNr      --> osNeedEnd:     msgNR (Hst, Single, 90%)
%%  osNeedNr      --> osNeedNr:      msgNR* (10%, ???, v1.85)
  osNeedCallNr  --> osNeedCall:    msgNR (Hst, Single, 90%)
%%  osNeedCallNr  --> osNeedCallNr:  msgNR (10%, v1.85)

%% Implied messages (Patience is decremented at each timeout event).
%% These implied messages do not change state, but the DxOperator.Patience value is decremented.
  osNeedCallNr      --> osNeedCallNr:      msgNR* (10%)
  osNeedNr      --> osNeedNr:      msgNR* (10%)
  osNeedCall     --> osNeedCall:   msgNR*
  osNeedNr  --> osNeedNr: msgQm*
%%  osNeedEnd     --> osNeedEnd:   msgNR*
%%  osNeedEnd     --> osNeedEnd:   IsMyCall=Yes*

%% New messages (1.85) - replace the items above...
%%  osNeedCallNr      --> osNeedCallNr:      msgNR (10%, P++, new)
%%  osNeedNr           --> osNeedNr:      msgNR (10%, P++, new)
%%  osNeedCall         --> osNeedCall:   msgNR (P++, new)
%%  osNeedEnd         --> osNeedEnd:   msgNR (P++, new)

%% DxOperator receives a 'TU' from the User
  osNeedPrevEnd --> osNeedQso: msgTU
  osNeedEnd     --> osDone:    msgTU
%%  osNeedNr    -->  osDone:    msgTU (new)
%%  osNeedCallNr  --> osNeedQso:    msgTU (new)
%%  osNeedCall     --> osDone:    msgTU (new)
%%  osNeedCall --> osDone: msgTU* (90%)			%% keep?
%%  osNeedCall --> osNeedQso: msgTU* (10%)		%% keep?

%% DxOperator receives a '?' from the User
%%  osNeedPrevEnd  --> osNeedQso:  msgQm (if Call.IsEmpty)
%% new msgQm messaging...
%%  osNeedQso  --> osNeedQso: msgQm*
%%  osNeedNr  --> osNeedNr: msgQm (P++, new)
%%  osNeedCall  --> osNeedCall: msgQm (P++, new)
%%  osNeedCallNr  --> osNeedCallNr: msgQm (P++, new)
%%  osNeedEnd  --> osNeedEnd: msgQm (P++, new)

  %%osNeedQso     --> osNeedQso: Timeout
%%  note right of osNeedQso
%%    DxStation will send his Callsign to user
%%    and wait for user to send their callsign.
%%  end note

%% Timeouts occur every 2-5 seconds or so. When Patience goes to zero, the DxStation will leave the QSO.
%%  osNeedCallNr --> osFailed: P=0
%%  osNeedNr      --> osFailed: P=0
%%  osNeedCall    --> osFailed: P=0
%%  osNeedQso    --> osFailed: P=0
%%  osNeedEnd    --> osFailed: P=0

  %%osNeedNr --> osNeedNr: Timeout
  %%osNeedEnd --> osNeedEnd: Timeout
  
  osDone --> [*]
%%  osFailed --> [*]

Notes

• There are five basic states in this QSO.
• These states should be viewed from the perspective of the remote Dx Station operator.
• Look for msgNR* or msgQm* ('?') states. These are each decrementing the Patience value towards zero and lead to caller ghosting.
• There are two additional states added as described below...

osNeedCallNr

• DxStation is expecting both their callsign and Exchange to be sent by user.
• This state is entered when the DxStation receives a partially-correct callsign from the user. In this case, the QSO advances from osNeedQso to osNeedCallNr.
• Once the correct callsign is received, the next state will be osNeedNr.
• Typical response msg: DxStation's callsign

osNeedCall

• DxStation is expecting their call to be corrected by the user.
• This state is entered when user sends a partially-correct callsign.
• This DxOperator will wait for the correct call to be sent before sending its Exchange.
• The logic also appears to support the fact the user's exchange (NR) has already been copied by this DxStation.
• Once corrected, we should send 'R '.
• Typical response msg: send DxStation's callsign

The Solution for Caller Ghosting

The root cause of caller ghosting was the unexpected decrementing of the DxOperator.Patience value during some of the exchange repeating messages between the User and the DxStation. Some of these were unexpected and lead to caller ghosting.

This problem was fixed by introducing a new function, DxOperator.MorePatience which would increase the Patience value whenever the user sends a message and the state does not change. The second commit (in the code review) introduces this new function and fixes this problem.

The state machine below shows the state machine with v1.85 changes showing additional events and Patience adjustments.

---
title: Basic Flow of a Typical QSO with Caller Ghosting Fixed (starting v1.85)
---
stateDiagram-v2
  [*] --> osNeedPrevEnd

%% msgCQ - DxOperator receives CQ from the User
%%  osNeedPrevEnd --> osNeedQso: msgCQ, P=[0,15]
  osNeedPrevEnd --> osNeedQso: msgCQ
%%  osNeedQso     --> osNeedQso: msgCQ*
  osNeedEnd     --> osDone:    msgCQ
%%  osNeedNr      --> osFailed:  msgCQ
%%  osNeedCall    --> osFailed:  msgCQ
%%  osNeedCallNr  --> osFailed:  msgCQ

%% IsMyCall=Yes - DxOperator receives his callsign from the user with an exact match
  osNeedPrevEnd --> osNeedNr:  IsMyCall=Yes
  osNeedQso     --> osNeedNr:  IsMyCall=Yes
  osNeedCallNr  --> osNeedNr:  IsMyCall=Yes
  osNeedCall    --> osNeedEnd: IsMyCall=Yes

%% IsMyCall=Almost - DxOperator receives a partial match of his callsign from the user
  osNeedPrevEnd --> osNeedCallNr: IsMyCall=Almost
  osNeedQso     --> osNeedCallNr: IsMyCall=Almost
  osNeedNr      --> osNeedCallNr: IsMyCall=Almost
  osNeedEnd     --> osNeedCall:   IsMyCall=Almost

%% IsMyCall=No - DxOperator receives a callsign from the user that does not match his callsign
  osNeedQso     --> osNeedPrevEnd: IsMyCall=No
%%  osNeedNr      --> osFailed:      IsMyCall=No
%%  osNeedCall    --> osFailed:      IsMyCall=No
%%  osNeedCallNr  --> osFailed:      IsMyCall=No
  osNeedEnd     --> osDone:        IsMyCall=No

%% msgNR - DxOperator receives exchange (NR) from the User
  osNeedQso     --> osNeedPrevEnd: msgNR
  osNeedNr      --> osNeedEnd:     msgNR (Hst, Single, 90%)
%%  osNeedNr      --> osNeedNr:      msgNR* (10%, ???, v1.85)
  osNeedCallNr  --> osNeedCall:    msgNR (Hst, Single, 90%)
%%  osNeedCallNr  --> osNeedCallNr:  msgNR (10%, v1.85)

%% Implied messages (Patience is decremented at each timeout event).
%% These implied messages do not change state, but the DxOperator.Patience value is decremented.
%%  osNeedCallNr      --> osNeedCallNr:      msgNR* (10%)
%%  osNeedNr      --> osNeedNr:      msgNR* (10%)
%%  osNeedCall     --> osNeedCall:   msgNR*
%%  osNeedNr  --> osNeedNr: msgQm*
%%  osNeedEnd     --> osNeedEnd:   msgNR*
%%  osNeedEnd     --> osNeedEnd:   IsMyCall=Yes*

%% New messages (1.85) - replace the items above...
  osNeedCallNr      --> osNeedCallNr:      msgNR (10%, P++, new)
  osNeedNr           --> osNeedNr:      msgNR (10%, P++, new)
  osNeedCall         --> osNeedCall:   msgNR (P++, new)
  osNeedEnd         --> osNeedEnd:   msgNR (P++, new)

%% DxOperator receives a 'TU' from the User
  osNeedPrevEnd --> osNeedQso: msgTU
  osNeedEnd     --> osDone:    msgTU
%%  osNeedNr    -->  osDone:    msgTU (new)
%%  osNeedCallNr  --> osNeedQso:    msgTU (new)
%%  osNeedCall     --> osDone:    msgTU (new)
%%  osNeedCall --> osDone: msgTU* (90%)			%% keep?
%%  osNeedCall --> osNeedQso: msgTU* (10%)		%% keep?

%% DxOperator receives a '?' from the User
%%  osNeedPrevEnd  --> osNeedQso:  msgQm (if Call.IsEmpty)
%% new msgQm messaging...
%%  osNeedQso  --> osNeedQso: msgQm*
%%  osNeedNr  --> osNeedNr: msgQm (P++, new)
%%  osNeedCall  --> osNeedCall: msgQm (P++, new)
%%  osNeedCallNr  --> osNeedCallNr: msgQm (P++, new)
%%  osNeedEnd  --> osNeedEnd: msgQm (P++, new)

  %%osNeedQso     --> osNeedQso: Timeout
%%  note right of osNeedQso
%%    DxStation will send his Callsign to user
%%    and wait for user to send their callsign.
%%  end note

%% Timeouts occur every 2-5 seconds or so. When Patience goes to zero, the DxStation will leave the QSO.
%%  osNeedCallNr --> osFailed: P=0
%%  osNeedNr      --> osFailed: P=0
%%  osNeedCall    --> osFailed: P=0
%%  osNeedQso    --> osFailed: P=0
%%  osNeedEnd    --> osFailed: P=0

  %%osNeedNr --> osNeedNr: Timeout
  %%osNeedEnd --> osNeedEnd: Timeout
  
  osDone --> [*]
%%  osFailed --> [*]

Notes

• New events are marked with an additional (P++, new) label indicating that Patience is incremented.

Logging Ghosted Calls in the Log

The final commit deals with logging a ghosted call into the log. This fixes the original problem reported in this Issue. Originally a ghosted call was deleted from the simulation and was not available at the time the User logged the QSO. To fix this, the DxStation object is not immediately deleted from the simulation, but is rather kept in memory as a ghosted call. An new function DxOperator.IsGhosting was added to indicate that the operator's patience had gone to zero. Changes were made to not transmit further messages. This allowed any messages from the User to be received by the ghosted DxStation and could then be subsequently logged by the User.

Below is a state machine showing the basic operational states of the DxStation object. The DxStation will cycle between 4 operational states:

1. stListening - waiting for Operator (the User) to send a message. (evMeStarted)
2. stCopying - stays in this state while Operator's message is transmitted. (evMeFinished)
3. stPreparingToSend - after receiving a message from Operator, the new message is prepared. After a brief delay time, this message is transmitted. (evTimeout)
4. stSending - DxStation's message is transmitted to the Operator. (Station.Tick)

---
title: Basic Flow of DxStation Operational States
---
stateDiagram-v2
%%  [*] --> stCopying: DxStation.CreateStation()
  [*] --> stListening

  stListening --> stCopying: evMeStarted
  stListening --> stPreparingToSend: evMeFinished

  stCopying --> stPreparingToSend: evMeFinished

  stPreparingToSend --> stSending: evTimeout
%%  stPreparingToSend --> stListening: evTimeout (if Oper.IsGhosting)
  stPreparingToSend --> stSending: SendMsg()
  stPreparingToSend --> stCopying: evMeStarted
%%  stPreparingToSend --> stPreparingToSend: evMeFinished

  stSending --> stPreparingToSend: evMeFinished
  stSending --> stListening: Dx Finished

Caller Ghosting Solution

To fix the problem of ghosted calls not showing up in the log, we formalize the notion of caller ghosting by introducing a DxOperator.IsGhosting function. When ghosting begins (indicated by Patience=0), the DxStation will:
a) stop transmitting
b) remain in memory while waiting for the User to respond or complete a QSO.

This allows the DxStation object to remain active while waiting for the User to complete the current QSO by sending 'TU' and logging the QSO.

The state machine below shows how caller ghosting will simply stop the station from entering transmit states (stPreparingToSend, stSending). Once the user sends the final 'TU' message (msgTU), this DxStation is logged and marked for deletion by setting Oper.State=osDone.

---
title: DxStation Operational States with Caller Ghosting
---
stateDiagram-v2
  [*] --> stListening

  stListening --> stCopying: evMeStarted

%%???  stListening --> stPreparingToSend: evMeFinished
  stListening --> IsGhosting: evMeFinished
  stCopying --> IsGhosting: evMeFinished

  state if_ghosting <<choice>>

  IsGhosting --> if_ghosting: Patience=0?
  if_ghosting --> stListening: Yes
  if_ghosting --> stPreparingToSend: No

  stPreparingToSend --> stSending: evTimeout
%%  stPreparingToSend --> stListening: evTimeout (if Oper.IsGhosting)
  stPreparingToSend --> stSending: SendMsg()
  stPreparingToSend --> stCopying: evMeStarted
%%  stPreparingToSend --> stPreparingToSend: evMeFinished

  stSending --> stPreparingToSend: evMeFinished
  stSending --> stListening: Dx Finished

[w7sst]

@scotthibbs @WR7Q
I have finally got a fix to this problem. Can you each take some time and test this for us? There is also a code review/pull request that I have included you on. Some of the code comments may help.

An engineering build of these changes are available here.

Thank you,
Mike W7SST