IDI-Systems / acre2

Advanced Combat Radio Environment 2 (ACRE2) for Arma 3
https://acre2.idi-systems.com
GNU General Public License v3.0
204 stars 117 forks source link

Radios break in various ways - can't hear or be heard #1163

Open simon-horny opened 2 years ago

simon-horny commented 2 years ago

Mods (complete and add to the following information):

(sorry for format, can't be arsed to parse that)

@CBA_A3;@ace;@RHSSAF;@RHSGREF;@RHSAFRF;@RHSUSAF;@CUP Weapons;@CUP Units;@ACE Compat - RHS SAF;@ACE Compat - RHS United States Armed Forces;@ACE Compat - RHS Armed Forces of the Russian Federation;@ACE Compat - RHS GREF;@Enhanced Movement;@ACRE2;@Simplex Support Services;@LAMBS_Dangerfsm;@LAMBS_RPG;@LAMBS_Suppression;@LAMBS_Turrets;@Ryans ACE Canteen;@CUP Terrains - Core;@CUP Terrains - Maps;@WMO - Walkable Moving Objects;@Zeus Enhanced;@Gruppe Adler Trenches;@3CB Factions;@Project OPFOR;@Zeus Enhanced - ACE3 Compatibility;@Advanced Sling Loading;@Advanced Towing;@Angola Maps v13;@Rosche Germany;@Antistasi - Sahrani - Community Version;@NIArms All In One V14 Onwards;@NIArms All in One - CUP Compatibility;@NIArms All in One- ACE Compatibility;@Prone Launcher;@MAAWS Additional Ammo Types;@CUP Vehicles

edit: changed to code block

Description: After playing for some time, gamebreaking behaviour occurs, we can hear each other over intercoms and direct voice, however some people report not being able to hear some people, from time to time one can be heard but will not get replies, as he's the one with broken radio, so generally speaking the materialisation of this bug is extremely chaotic. It really breaks my heart to let go of ACRE but mission is basically over once we have no comms. Hopefully this bug report will be dealt with and if there are other people with the same issue, it might help them.

Steps to reproduce:

It's extremely difficult to pinpoint where the issue occurs exactly as... it just happens.

Expected behavior: Radios to work.

Where did the issue occur?

Log Files:

jonpas commented 2 years ago

RPT has duplicate ID warnings. Since you point out it happens after respawn, your respawn script probably assigns the radio with same ID, resulting in a duplicate radio. Respawn loadout should give base radios.

Share a mission where that happened. It would also be good to have RPT of the one that couldn't talk and describe in detail when it started happening and for who.

simon-horny commented 2 years ago

Yeah I thought it might be the duplicate radio IDs. Now since I am not a mission maker myself, I had no clue about the respawn script, however that put me on track, now I know where to start. I'm gonna ask the mission maker about it and see where that gets me.

simon-horny commented 2 years ago

New info, we use native ACE script, so that is maybe at fault?

jonpas commented 2 years ago

@simon-horny Somehow missed this. What do you mean with "native ACE script"?

simon-horny commented 2 years ago

It is an option in addon options, ACE Respawn, Save gear, ace_respawn_savePreDeathGear.

jonpas commented 2 years ago

I don't believe that does any filtering, so yes, it could be it.

jonpas commented 2 years ago

@simon-horny Have you by any chance tried without ACE's Save Gear?

TACHarsis commented 2 years ago

We also experience this issue a lot lately after not having had serious ACRE issues for months. Happens to people that respawn and those that don't equally. It also seems to only occur some ways (an hour or so) into the mission.

NNewtonn commented 1 year ago

We also experience this issue a lot lately after not having had serious ACRE issues for months. Happens to people that respawn and those that don't equally. It also seems to only occur some ways (an hour or so) into the mission.

We got exactly the same issue

3cb commented 1 year ago

@simon-horny not sure why my username got mentioned here; I don't even know what this is. Could you edit it out of the original post so I stop getting emails about this issue? Thanks.

Drofseh commented 1 year ago

@simon-horny not sure why my username got mentioned here; I don't even know what this is. Could you edit it out of the original post so I stop getting emails about this issue? Thanks.

On the right side there shoudl be a Notifications section, click on unsubscribe

rautamiekka commented 1 year ago

@simon-horny not sure why my username got mentioned here; I don't even know what this is. Could you edit it out of the original post so I stop getting emails about this issue? Thanks.

Some ppl, like OP, don't realize that GitHub uses @ for user tagging, which is used by 'Arma'/'OFP' mod folders.

fastgunner commented 1 year ago

apologies for reviving an older bug thread. Is there a way to force assign a new radio ID on respawn while still using the ace respawn?

My thoughts were running

acre2RadioIDSet = randomNumber

in the onPlayerRespawn.sqf. I'm more than happy to come back with a working solution. Just not sure what calls are available for ACRE and the website documentation doesn't include this as an option.

Drofseh commented 1 year ago

apologies for reviving an older bug thread. Is there a way to force assign a new radio ID on respawn while still using the ace respawn?

My thoughts were running

acre2RadioIDSet = randomNumber

in the onPlayerRespawn.sqf. I'm more than happy to come back with a working solution. Just not sure what calls are available for ACRE and the website documentation doesn't include this as an option.

You should never assign radio IDs manually. This will cause multiple radios with duplicate IDs to exist in the mission and screw thigns up. Your respawn script should only ever assign radios with no ID, then the server will automatically assign an unused ID.

If your respawn script is giving you a new radio with the ID of an existing radio, then you should filter your respawn script using acre_api_fnc_filterUnitLoadout

TACHarsis commented 1 year ago

We had a particularly bad case last op, judging from the logs.

Enclosed is the server log and the logs of the two players that were impacted most severely, according to the acre error messages. Both of them experienced pipe errors and connection issues around the time the communication outages started. All loadouts get sanitized and do not contain duplicate/unique radio IDs neither on mission start nor during loadout changes or respawns.

Hope that helps and let me know if I can provide more context.

acre issues.zip

TACHarsis commented 1 year ago

Did someone take a look at those logs already? We keep having these issues, last time ~1hr into the op. It's rather frustrating.

jonpas commented 1 year ago

@TACHarsis Apologies for getting back to this so late, but I did look at the logs. Relevant bits I found:

SERVER
19:29:46 [ACRE] (sys_server) WARNING: Id object relation created independently of unique ID creation process (acre_prc152_id_13)!
19:29:46 [ACRE] (sys_server) WARNING: Id object relation created independently of unique ID creation process (acre_prc152_id_9)!
19:29:46 [ACRE] (sys_server) WARNING: Id object relation created independently of unique ID creation process (acre_prc117f_id_6)!
... quite a few of these, looks like for each player.

CLIENTS
21:08:34 [ACRE] (sys_data) WARNING: Non-existent radio 'acre_prc152_id_9' called isExternalAudio system event!
21:08:34 [ACRE] (sys_data) WARNING: Non-existent radio 'acre_prc152_id_9' called isExternalAudio radio event!
21:08:34 [ACRE] (sys_data) WARNING: Non-existent radio 'acre_prc152_id_17' called isExternalAudio system event!
...
20:56:41 [ACRE] (sys_data) WARNING: Non-existent radio 'ACRE_PRC343' called getOnOffState system event!
20:56:41 [ACRE] (sys_data) WARNING: Non-existent radio 'ACRE_PRC343' called getOnOffState radio event!
...
20:56:06 [ACRE] (sys_radio) WARNING: acre_prc343_id_17 was found in personal inventory but is uninitialized! Trying to collect new ID.
20:56:06 [ACRE] (sys_radio) WARNING: acre_prc152_id_12 was found in personal inventory but is uninitialized! Trying to collect new ID.
...
20:35:52 [ACRE] (sys_data) WARNING: Non-existent radio 'acre_prc343_id_10' called getState system event!
20:35:52 [ACRE] (sys_data) WARNING: Non-existent radio 'acre_prc343_id_10' called getState radio event!
...
20:35:52 [ACRE] (sys_server) ERROR: Your radio 'acre_prc343_id_10' is being garbage collected. The server believes you do not have this radio.
20:30:19 [ACRE] (sys_server) ERROR: Your radio 'acre_prc343_id_10' is being garbage collected. The server believes you do not have this radio.
20:30:19 [ACRE] (sys_server) ERROR: Your radio 'acre_prc152_id_5' is being garbage collected. The server believes you do not have this radio.
... and a lot of pipe errors

That error is definitely at least part of the problem here. Server is basically garbage collecting "active" radios (active for clients, gone for server).

It looks like you are also adding radios with their IDs, or some other form of loadout/inventory breaking.


Client Jaiden also has some worrying messages in the plugin logs:

[13:54:22.895] WARNING! WARNING! Teamspeak is possibly running in Windows Audio Session playback mode. This mode does not correctly determine surround sound channels!
[13:54:22.895] WARNING! WARNING! ACRE IS NOW INITIALIZING POSITIONAL AUDIO IN STEREO MODE!

This could result in issues such as per-ear playback and similar, in most cases it is fine though.

NZF-JDWang commented 1 year ago

Just to add a little more information here so it doesn't get lost in Discord. When we have this issue we've noticed the person who can't be heard can start transmitting and count to 10, usually by the time they hit 5 or 6 people will start to hear them. (and we all start to hear them at the same time) If they do the same check again, once more we cannot hear then until about 5 or 6.

Last nights Zeus mission we had the issue maybe 20 mins into the mission (even before anyone had died or respawned), and then later on people having the issue found their radios would come right, then fail again. Server wasn't under any real stress and performance was good.

Also for the record we I don't have any radio pre-assignment or use any of the ACRE functions to set things up. Our players simply grab their radios from an ACE arsenal.

jonpas commented 9 months ago

Had this happen a while ago, for the first time. Or at least same symptoms.

Got an error from the extension callback added in this PR. Sadly game decided to overwrite RPT (*), but it was something about invalid callback variable in callExt.

I didn't receive anything on any radio until I restarted the game. Just relogging back to lobby and back into the game gave me the error in XEH_preInit.

At the same time, Arma decided to give me a major inventory desync as half of my stuff wasn't even visible to the server (our persistence system on server didn't see it).

I believe this is where the error originated from.

(*) Whoever wrote the RPT handling logic for Arma (3)... You can start it as arma3.exe or Arma3.exe because Windows is case-insensitive. But whatever you use, Arma will use as the RPT name. All good, until you start arma3 a bunch of times, then do Arma3 twice in a row, and it deletes the newest RPT - seemingly counts them case-insensitive but finds oldest case-sensitive? XD


All this tells me is that inventory desync in Arma itself is still problematic, after a whole decade.

mrschick commented 6 months ago

I finally encountered this bug this past Monday while Zeusing in a mission, so at least I could spawn a radio crate to try to resolve those issues. I was also recording so I can now trace what happened to the logs, fwiw...

It appears I was the only one it affected, it occurred spontaneously 40 minutes into the mission and resolved itself 52 minutes in seemingly on its own, having changed radios multiple times in between. Only radio communication was interrupted, apparently I was heard but could not receive anyone, except for a single communication 47 minutes in right after having changed channel. Direct chat appeared entirely unaffected.

We were running our fork of ACRE2, specifically the bagigi branch with the fe7dc271 commit, all extensions used are from the latest public build v2.12.0.1056.

Log files from myself and the server. Logs_2023-12-11_21-09-29.zip

Analysis of events, timestamps are in local time, corresponding to the logs:

Until then, everything worked as expected, I had my PRC-117F set to Ch1 for platoon-level comms and a PRC-152 on Ch2 to monitor comms within Alpha Squad.

22:37:19 - Last known communication on Ch1 received from Alpha-SL before bug's occurrence.

22:37:47 - While talking in direct chat to Delta-SL, he starts transmitting on Ch1 but I notice that I'm not receiving despite being next to him.

22:38:20 - Both Delta-SL and a squad member who carries a PRC-152 do a check on Ch1, they are received by other SLs further away but not by me.

22:38:33 - I do a check on Ch1 but nobody receives my transmission.

From here i TP away to troubleshoot, staying within radio range of any Ch1 and Ch2 transmitters.

22:40:29 - I edit my loadout, entering the ACE Arsenal and remove my PRC-117F, at that point I was carrying PRC117F_ID_4 and PRC152_ID_15, then regive myself a fresh PRC-117F and close the arsenal. Check Ch1, no reply.

22:42:23 - SLs apparently could hear me, but I didn't receive them at all. At this point I spawn a standard ACRE radio crate and drop all my radios to the ground, then take a fresh PRC-117F and PRC-152 from the crate. Checking the arsenal again reveals that the new PRC-117F's ID is 4, the same of the one I just dropped, so I remove it via the arsenal. The new PRC-152 has ID 18 and is now set to Ch1, but I still don't receive anyone on it in the next minutes. Keying the PRC-117F to check also doesn't ever result in an audible click from the PRC-152 on the same channel.

22:43:35 - I finally overhear a "send traffic" communication from Bravo-SL, but that only confirms that I'm not hearing the previous or following communication from Alpha-SL. So I get back to my radio crate and grab a fresh PRC-117F, checking the arsenal again reveals it has ID 4.

22:44:29 - Out of curiosity I set my PRC-152 (ID 18) to Ch2, immediately I start receiving traffic between Alpha's FTLs and SL without apparent issues. So I just say to hell with the bugged PRC-117F and take a second fresh PRC-152 out of the crate to monitor Ch1. Ch2 falls silent again despite others later confirming there was traffic, Ch1 is still not being received while I hear Alpha-SL through the Zeus camera trying to contact me.

22:47:00 - I set my newest PRC-152 from Ch2 to Ch1, to check if it works and Alpha is just not speaking, it still doesn't.

22:48:09 - I place my Zeus camera next to a few guys and overhear their direct voice convo, then open the ace medical menu of a nearby casualty from the Zeus interface (a feature of Zeus Additions), the DV convo I was hearing was instantly muted, after exiting exiting the menu I don't hear the first guy finishing his phrase, only the second guy replying after 2 seconds. This is probably expected DV behaviour due to the way remoteStartSpeaking et al work, just adding for completeness.

22:48:41 - One of the few guys from before starts a transmission on Ch1, which I again fail to receive.

22:50:09 - I suddenly start receiving platoon-level Ch1 comms from multiple squad leaders again, this applies to both my PRC-152s as I hear double "clicks" at the end of transmissions. From there I set them to different ears, one of them to Ch2 and continue as initially planned, no further issues for the entire >1h of the mission.

I hope this can help, unfortunately the logs don't really seem to be outputting much information.

mrschick commented 5 months ago

Is there some debug flag that I could enable in a component (my community uses a Fork) to get better log info when this happens again?

jonpas commented 5 months ago

You can enable acre_sys_signal_showSignalHint = true; and ACRE_SIGNAL_DEBUGGING = 1;. First will show a hint with currently receiving signal (even ones system is capturing but you can't hear because it's too low) and second one will log a lot of signal data to the RPT. Ref. https://acre2.idi-systems.com/wiki/frameworks/radio-signal-debugging

We've pretty much established it's not signal calculation issue itself, as map visualization debug tool would show that. Large suspect at the moment is something in the pipeline getting clogged, likely between the game and the extension.

I am not finding time for it, but the proper way to debug this at this point would be to add some extension buffer metrics we could look at at the time of failure. This requires someone to dive into C++ extensions as well as SQF. I am however available to "release" debug builds with as much additional debug metrics included as possible, or even with "assumption fixes" (or best guesses of what could be wrong).

mrschick commented 5 months ago

We've pretty much established it's not signal calculation issue itself, as map visualization debug tool would show that. Large suspect at the moment is something in the pipeline getting clogged, likely between the game and the extension.

That's our observation as well, comms break despite being right next to players who don't have any issues receiving or being heard by a third party.

I am however available to "release" debug builds with as much additional debug metrics included as possible, or even with "assumption fixes" (or best guesses of what could be wrong).

Would gladly use those changes in our fork to do medium-large scale testing 👍🏻