hbeni / fgcom-mumble

A (flightsim) radio communication simulation based on mumble
GNU General Public License v3.0
17 stars 5 forks source link

Bug: Two identites in one mumble plugin do not report correctly to statusbot #169

Closed hbeni closed 1 year ago

hbeni commented 1 year ago

Describe the bug Two identites in one plugin instance do not show on the statuspage.

To Reproduce

Expected behavior Both identites should report on the statupage.

Logfiles Statusbot parses:

JSON RESULT: {"meta":{"highscore_clients":2, "highscore_date":1689057629}, "clients":[{"radios":{"0":{"srv":1, "dialedFRQ":"122.75", "vlt":12, "operable":"1", "ptt":"0", "power":"10.000000", "pbt":1, "frequency":"122.7500"}, "1":{"srv":1, "dialedFRQ":"121.5", "vlt":12, "operable":"1", "ptt":"0", "power":"10.000000", "pbt":1, "frequency":"121.5000"}}, "updated":1689058188, "alt":"639.478149", "callsign":"D-EBHX", "lat":"39.553207", "lon":"-31.121721", "type":"client"}]}
Parsing done. New remote state:
sid=58; idty=1    radio #0 frequency='122.7500'
sid=58; idty=1    radio #0 dialedFRQ='122.75'
sid=58; idty=1    radio #0       ptt='0'
sid=58; idty=1    radio #0       pwr='10.000000'
sid=58; idty=1    radio #0       opr='1'
sid=58; idty=1    radio #1 frequency='121.5000'
sid=58; idty=1    radio #1 dialedFRQ='121.5'
sid=58; idty=1    radio #1       ptt='0'
sid=58; idty=1    radio #1       pwr='10.000000'
sid=58; idty=1    radio #1       opr='1'
sid=58; idty=1  type:   client
sid=58; idty=1  lastUpdate:     1689058190
sid=58; idty=1  callsign:       D-EBHX
sid=58; idty=1  lat:    39.554123
sid=58; idty=1  lon:    -31.121862
sid=58; idty=1  alt:    644.964661
-----------

Plugin internal tate is OK tough: grafik

hbeni commented 1 year ago

Hm, maybe we just miss the PING packets from the first identity, to keep the state alive?

Pushing PTT in radioGui after the entry vanished restores a client entry in the table (without callsign and location, tough)

hbeni commented 1 year ago

Ping is sent:

FGCom [2023-07-11 09:01:57.017]: [DBG] [mum_pluginIO] fgcom_notifyThread() Ping is due.
FGCom [2023-07-11 09:01:57.017]: [DBG] [mum_pluginIO] notifyRemotes(0,5,-1,0) called
FGCom [2023-07-11 09:01:57.017]: [DBG] [mum_pluginIO] notifyRemotes(): we are connected, so notifications will be sent.
FGCom [2023-07-11 09:01:57.017]: [DBG] [mum_pluginIO] notifyRemotes(): successfully resolved identity='0' (callsign=test2)
FGCom [2023-07-11 09:01:57.017]: [DBG] There are 3 users on this channel.
FGCom [2023-07-11 09:01:57.017]: [DBG]   sending message to: 47
FGCom [2023-07-11 09:01:57.017]: [DBG]   sending message to: 46
FGCom [2023-07-11 09:01:57.018]: [DBG]   ignored local user: id=59
FGCom [2023-07-11 09:01:57.018]: [DBG]   message sent to 2 clients
FGCom [2023-07-11 09:01:57.018]: [DBG] [mum_pluginIO] message was: '0,1'
FGCom [2023-07-11 09:01:57.018]: [DBG] [mum_pluginIO] notification for dataID='FGCOM:PING' done.

Maybe ping is not processed correctly from the bots?

hbeni commented 1 year ago

No, ping is received:

DATA INCOMING FROM=59
Received FGCOM-plugin data, dataID='FGCOM:PING', from=[59] 'D-EBHX'
  data='0,1'
  datatype='FGCOM'
  packtype='PING'
ping packet for sid=59; iid=0
ping packet for sid=59; iid=1
Parsing done. New remote state:
sid=59; idty=0    radio #0 frequency='test'
sid=59; idty=0    radio #0 dialedFRQ='test'
sid=59; idty=0    radio #0       ptt='0'
sid=59; idty=0    radio #0       pwr='10.000000'
sid=59; idty=0    radio #0       opr='1'
sid=59; idty=0  type:   client
sid=59; idty=0  lastUpdate:     1689059217
sid=59; idty=0  callsign:
sid=59; idty=0  lat:
sid=59; idty=0  lon:
sid=59; idty=0  alt:
sid=59; idty=1  type:   client
sid=59; idty=1  lastUpdate:     1689059217
sid=59; idty=1  callsign:       D-EBHX
sid=59; idty=1  lat:    39.655670
sid=59; idty=1  lon:    -31.137465
sid=59; idty=1  alt:    1066.203369
-----------
hbeni commented 1 year ago

Intersting: generateOutData(): number of known users: 0 Probably only an artifact of logging as DB is created with two clients.

hbeni commented 1 year ago

After restarting mumble (logs came from that instance), all seems well and stable....

hbeni commented 1 year ago

Thesis: When one identity has recently changed data, no ping packet is generated anymore, even if the other identity had no data change.

To Reproduce: RadioGUI sits idle, plane is flying


Seems to confirm itself. Last ping was: FGCom [2023-07-11 09:33:24.225]: [DBG] [mum_pluginIO] fgcom_notifyThread() Ping is due. Now is 9:40 and the IID=0 should have pinged long ago.

Also, investigated the code; reason looks like the last ping ist recored pluginwide instead in the scope of the identity

hbeni commented 1 year ago

After fix, test was OK for ~2 hrs or so