VeniceUnleashed / VeniceUnleashed

Venice Unleashed community tracker.
https://veniceunleashed.net
95 stars 6 forks source link

[Bug] No weapon after respawn #890

Open toba-zz opened 1 year ago

toba-zz commented 1 year ago

Sometimes after respawn you don't have weapons, HUD shows bullets information when you change weapon but you don't see it and you can't shoot.

https://youtu.be/KvhJlq9l54I

Experiment 1 (mod) I decided respawn itself with weapons, well didn't work. If you have weapon works fine, but after lost weapons you can't get weapons with respawning.

Then I hook "ResourceManager:LoadBundles" and subscribe to "ResourceManager:ClearCompartment"

normal behaviour

[2022-12-21 16:25:41+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-21 16:25:41+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M416/M416_SoldierWeaponBundle,}
[2022-12-21 16:25:41+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M9/M9_SoldierWeaponBundle,}
[2022-12-21 16:25:41+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Medicbag/MedicBag_SoldierWeaponBundle,}
[2022-12-21 16:25:41+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Defibrillator/Defibrillator_SoldierWeaponBundle,}
[2022-12-21 16:25:41+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M67/M67_SoldierWeaponBundle,}
[2022-12-21 16:25:41+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/XP2_Knife_RazorBlade/Knife_RazorBlade_SoldierWeaponBundle,}
[2022-12-21 16:27:20+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:ClearCompartment 105
[2022-12-21 16:27:20+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:ClearCompartment 106
[2022-12-21 16:27:20+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:ClearCompartment 107
[2022-12-21 16:27:20+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:ClearCompartment 108
[2022-12-21 16:27:20+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:ClearCompartment 109
[2022-12-21 16:27:20+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:ClearCompartment 110

BUG: LoadBundles is called but ClearCompartment is missing "press F3" is my mod to forced respawn player which works fine when you have weapon (LoadBundles and ClearCompartment shows) but if you lost weapon you can set new soldier, you also load weapons and assign them to soldier, but they don't show. Here I can see LoadBundles message but ClearCompartment don't show, after this LoadBundles don't show when you respawn

weapon don't show

[2022-12-21 16:28:06+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-21 16:28:06+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M416/M416_SoldierWeaponBundle,}
[2022-12-21 16:28:06+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M9/M9_SoldierWeaponBundle,}
[2022-12-21 16:28:06+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Medicbag/MedicBag_SoldierWeaponBundle,}
[2022-12-21 16:28:06+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Defibrillator/Defibrillator_SoldierWeaponBundle,}
[2022-12-21 16:28:06+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M67/M67_SoldierWeaponBundle,}
[2022-12-21 16:28:06+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/XP2_Knife_RazorBlade/Knife_RazorBlade_SoldierWeaponBundle,}
[2022-12-21 16:28:13+01:00] [info] [VeniceEXT] [soldier_data] press F3
[2022-12-21 16:28:13+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-21 16:28:13+01:00] [info] [VeniceEXT] [soldier_data] client.player killed 5
[2022-12-21 16:28:17+01:00] [info] [VeniceEXT] [soldier_data] press F3
[2022-12-21 16:28:18+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-21 16:28:18+01:00] [info] [VeniceEXT] [soldier_data] client.player killed 6

Delayed LoadBundles after respawn

[2022-12-21 10:53:41+01:00] [info] [VeniceEXT] [soldier_data] player respawn
[2022-12-21 10:54:29+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M416/M416_SoldierWeaponBundle,}
[2022-12-21 10:54:29+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M9/M9_SoldierWeaponBundle,}
[2022-12-21 10:54:29+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Medicbag/MedicBag_SoldierWeaponBundle,}
[2022-12-21 10:54:29+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Defibrillator/Defibrillator_SoldierWeaponBundle,}
[2022-12-21 10:54:29+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M67/M67_SoldierWeaponBundle,}
[2022-12-21 10:54:29+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/XP2_Knife_RazorBlade/Knife_RazorBlade_SoldierWeaponBundle,}

Complete log of video 10:15:28 call LoadBundles (but weapon missing) 10:23:43 call ClearCompartment is called and weapon shows

bug_no_weapon_video_vu_2022-12-22_10-11-40_0151.log

FlashHit commented 1 year ago

So you say normally the issue is that it’s not clearing the compartments on kill? Kinda looks weird since the respawn print happens before the kill print.

toba-zz commented 1 year ago

ClearCompartment is always common. I don't say is main reason why this happen but, when ClearCompartment not show in log then you respawn without weapon. And also ClearCompartment can show delayed and then is weapon again visible. Last log for video show how is stucked ClearCompartment related to not show weapon, but after few minutes is ClearCompartment show in log and previous LoadBundles calls are processed. This is pure random behaviour, yesterday I play damavand peak for test this and each game I lost weapon randomly after respawn, one game was without lost weapon another one was after 3rd respawn.

And yes order of events player.respawn and player.killed is weird. Is possible respawn start then is followed by kill and respawn is blocked or cancelled when kill set flags.

This is log with synchronized server+client messages (before ClearCompartment) Number after player killed is number of "Player:Killed" event

On server side is "Player:Killed" generated when you get hit and wait for revive and also when respawn without revive

On client side is "Player:Killed" generated only when you respawn after no revive

[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] server player respawn
[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M416/M416_SoldierWeaponBundle,}
[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M9/M9_SoldierWeaponBundle,}
[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Medicbag/MedicBag_SoldierWeaponBundle,}
[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Defibrillator/Defibrillator_SoldierWeaponBundle,}
[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M67/M67_SoldierWeaponBundle,}
[2022-12-21 14:08:47+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/XP2_Knife_RazorBlade/Knife_RazorBlade_SoldierWeaponBundle,}
//got hit and wait for revive
[2022-12-21 14:10:39+01:00] [info] [VeniceEXT] [soldier_data] server.player killed 1
//revived
[2022-12-21 14:10:42+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-21 14:10:42+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M9/M9_SoldierWeaponBundle,}
[2022-12-21 14:10:42+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Medicbag/MedicBag_SoldierWeaponBundle,}
[2022-12-21 14:10:42+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/Gadgets/Defibrillator/Defibrillator_SoldierWeaponBundle,}
[2022-12-21 14:10:42+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M67/M67_SoldierWeaponBundle,}
[2022-12-21 14:10:42+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/XP2_Knife_RazorBlade/Knife_RazorBlade_SoldierWeaponBundle,}
[2022-12-21 14:10:42+01:00] [info] [VeniceEXT] [soldier_data] ResManager:LoadBundles { [1] = Weapons/M416/M416_SoldierWeaponBundle,}
//immediatelly got hit no revive
[2022-12-21 14:10:44+01:00] [info] [VeniceEXT] [soldier_data] server.player killed 2
[2022-12-21 14:10:44+01:00] [info] [VeniceEXT] [soldier_data] client.player killed 1
//respawn without weapon
[2022-12-21 14:11:00+01:00] [info] [VeniceEXT] [soldier_data] server player respawn
[2022-12-21 14:11:00+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
//forced respawn itself via mod
[2022-12-21 14:13:17+01:00] [info] [VeniceEXT] [soldier_data] press F3
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] server player reload
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] player.soldier:Kill()
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] server.player killed 3
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] player.soldier:Kill() done
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] player:SpawnSoldierAt
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] player:SpawnSoldierAt done
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-21 14:13:18+01:00] [info] [VeniceEXT] [soldier_data] client.player killed 2
FlashHit commented 1 year ago

Okay, thanks for investigating. This is useful information. If you have time you could try to use whatever = ResourceManager:BeginClear(105) etc. You will need to use the Engine:Update event and then check if ResourceManager:Poll(whatever) then ResourceManager:EndClear(whatever). Sth like this. So you would manually clear the compartment. Ofc this is not a proper fix but it would be interesting to see if that works.

toba-zz commented 1 year ago

I have same idea but BeginClear(), EndClear() crash game, thus I didn't continue. Anyway I tested again and use ResourceManager:PollBundleOperation() check status of BeginClear() handle. (still don't know if use it properly)

When weapon not show call, BeginClear() didn't help. But show problem. beginclear_poll_deadlock_vu_2022-12-22_17-45-40_0319.log

Call BeginClear() when weapon was ok. PollBundleOperation() operation took 4 cycles to return TRUE

[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] press F3
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] clear_com = 0
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:BeginClear(105)
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 105
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:47:06+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:Poll(res_id) == true

Call BeginClear() when weapon not show.

[2022-12-22 17:49:05+01:00] [info] [VeniceEXT] [soldier_data] client.player killed 2
[2022-12-22 17:49:21+01:00] [info] [VeniceEXT] [soldier_data] client.player respawn
[2022-12-22 17:49:27+01:00] [info] [VeniceEXT] [soldier_data] client.player killed 3
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] press F3
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] clear_com = 0
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:BeginClear(105)
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 105
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:49:38+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1

Engine:Update clear_comp == 1 took ~4minutes (ResourceManager:Poll(res_id) == false) After this time ResourceManager:Poll(res_id) return true to my BeginClear(). BeginClear() call work normally after this issue.

[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 105
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 106
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 107
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 108
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 109
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] [client] ResourceManager:ClearCompartment 110
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] Engine:Update clear_comp == 1
[2022-12-22 17:53:16+01:00] [info] [VeniceEXT] [soldier_data] ResourceManager:Poll(res_id) == true
toba-zz commented 1 year ago

additional merged server+client log with chat message "lost weapon" "weapon show" to see when it happen no_weapon_bug_server_client_logs 20221223_2130.log