[http://sourceforge.net/p/ufoai/bugs/2606 Item 2606] imported from sourceforge.net tracker on 2013-01-28 19:43:45

Happened when i pressed the button to retry a mission.

2010/06/29 16:43:29 ********************
2010/06/29 16:43:29 ERROR: InvAdd message ignored... LE not found

2010/06/29 16:43:29 ********************
2010/06/29 16:43:29 Shutdown server: Server crashed.
2010/06/29 16:43:29 ==== ShutdownGame ====
===== Comments Ported from Sourceforge =====

====== zhdophanti (2010-06-29 14:50:11) ======

Seems like the old errors refered to 2.2 and should have been fixed with 2.3 .. if these patches are not included in 2.3 feel free to close this duplicate ;)
====== tlh2000 (2010-08-21 10:39:05) ======

i'm not exactly understanding what you are saying in your comment - is this still an issue or not?
====== zhdophanti (2010-08-21 15:48:59) ======

According to old bug entries (i did a little search), it seemed like this was already fixed in 2.2! But i encountered this bug in 2.3 as well, so maybe its a new bug.

I wasn't sure if it is something new, cause there exist many other bugs which are marked as solved on this error.
====== geever (2011-05-18 19:11:58) ======

I could reproduce this with the current master. Ask Retry in aliens turn -> map restarted with no actors spawned -> LE not found. This should be investigated/fixed for 2.4.

-geever
====== tlh2000 (2011-05-22 09:34:55) ======

i can reproduce this in skirmish in current master
====== tlh2000 (2011-05-22 10:07:59) ======

must be sv_threads related - setting this cvar to 0 does fix the bug
====== tlh2000 (2011-07-05 19:33:24) ======

this time it looks like it happened during a normal game

2011/07/05 17:29:20 setting game random seed to 4473142
2011/07/05 17:29:20 ------- Loading game.so -------
2011/07/05 17:29:20 not found at '/usr/local/lib'
2011/07/05 17:29:20 not found at '/home/elliot/.ufoai/2.4-dev/base'
2011/07/05 17:29:20 found at './base'
2011/07/05 17:29:20 tiles: -ufocrash/uc_ +craft_drop_firebird +craft_crash_fighter +h04 +h01 +h05 +h05 +h01 +h02 +h02 +h02
2011/07/05 17:29:20 pos: -16 -16 0 -16 0 0 8 -16 0 16 -16 0 -24 -16 0 -24 0 0 -24 16 0 -8 16 0 24 8 0 24 16 0
2011/07/05 17:29:20 tiles: 10
2011/07/05 17:29:20 CM_LoadMap: "-ufocrash/uc_ +craft_drop_firebird +craft_crash_fighter +h04 +h01 +h05 +h05 +h01 +h02 +h02 +h02" "-16 -16 0 -16 0 0 8 -16 0 16 -16 0 -24 -16 0 -24 0 0 -24 16 0 -8 16 0 24 8 0 24 16 0"
2011/07/05 17:29:21 Rerouted for RMA in 0.0s
2011/07/05 17:29:21 checksum for the map '+ufocrash': 2004260962
2011/07/05 17:29:21 ufo script checksum 2794599063
2011/07/05 17:29:21 -------------------------------------
2011/07/05 17:29:21 Connecting to localhost...
2011/07/05 17:29:21 ==== ShutdownGame ====
2011/07/05 17:29:21 Used inventory slots in game on shutdown: 0
2011/07/05 17:29:21 ==== InitGame ====
2011/07/05 17:29:21 Not enough spawn points for team 0
2011/07/05 17:29:21 Created AI player (team 0)
2011/07/05 17:29:21 Created AI player (team 7)
2011/07/05 17:29:21 Used inventory slots after ai spawn: 0
2011/07/05 17:29:21 connection attempt from loopback connection
2011/07/05 17:29:22 load material file: 'materials/ufocrash.mat'
2011/07/05 17:29:22 added light, ambient=0.476837
2011/07/05 17:29:23 Starting the game...
2011/07/05 17:29:23 SingularityCat has joined team 1
2011/07/05 17:29:23 music change to PsymongO2 (from PsymongO4)
2011/07/05 17:29:23 Used inventory slots: 0
2011/07/05 17:29:23 music change to Crystan-Battlescape02 (from PsymongO2)
2011/07/05 17:29:23 Used inventory slots client SingularityCat spawn: 0
2011/07/05 17:29:23 (player 0) It's team 1's round
2011/07/05 17:29:23 SingularityCat has taken control over team 1.
2011/07/05 17:29:39 [STATS] SingularityCat (Feng Dong) kills alien (Uuorgh Ur Uor Umhfm) with Single Shot of shotgun2_slug_ammo
2011/07/05 17:30:24 [STATS] SingularityCat (Andre Snow) kills alien (Ourhg Uk Ohm Umhpf) with Full-Auto of assault_ammo
2011/07/05 17:30:35 2011/07/05 17:30:36 2011/07/05 17:30:36 2011/07/05 17:30:36 2011/07/05 17:30:36 2011/07/05 17:30:36 2011/07/05 17:30:36 2011/07/05 17:30:36 2011/07/05 17:30:37 2011/07/05 17:30:38 2011/07/05 17:30:38 2011/07/05 17:30:38 2011/07/05 17:31:58 [STATS] alien (Ourhg Ws Our Hfmzs) kills civilian (b c) with Snap Shot of plaspistol_ammo
2011/07/05 17:31:58 Ourhg Ws Our Hfmzs is consumed by mad rage!
2011/07/05 17:31:58 Team 1 ended round
2011/07/05 17:31:58 Team 7's round started!
2011/07/05 17:32:01 ********************
2011/07/05 17:32:01 ERROR: InvAdd message ignored... LE not found

2011/07/05 17:32:01 ********************

====== tlh2000 (2011-09-23 07:19:37) ======

https://sourceforge.net/tracker/index.php?func=detail&aid=3412893&group_id=157793&atid=805242
====== tlh2000 (2011-09-24 07:27:57) ======

the error message was changed in 6ab9b9a73ff98bb465b30bcdae39534667e8796c

in debug mode you will now also get a list of local entities and a list of server side edicts. that might help to tackle it down

if anyone can find a reliable way to reproduce it, please let me know.
====== tlh2000 (2011-10-04 20:58:37) ======

i think i also saw this with sv_threads to 0 - so maybe it's not thread related.
====== tlh2000 (2011-10-04 21:09:14) ======

the inventory event code got some fixes for temp containers recently - we have to verify that this is still a bug
====== tlh2000 (2011-10-04 21:12:44) ======

use the sv_threads cvar to trigger the server side logic
====== aduke1 (2011-10-05 19:28:45) ======

I used geever's method (click Retry during alien turn). It worked after they killed one of my soldiers.
But I got an "LE_NotFoundError: Could not get LE with entnum 83".

So the question is: is this the same bug after those fixes mentioned below ?
====== tlh2000 (2011-10-05 20:18:14) ======

i suppose yes - there should be more output in ufoconsole.log if you run a debug build (the edict and le list)
====== aduke1 (2011-10-05 20:21:54) ======

Oh, and sv_threads was 0 !
====== tlh2000 (2011-10-06 08:09:12) ======

does this produce the error?
---------
console command "debug_killteam 1 1"
end round
retry game while it's the aliens turn
---------
====== aduke1 (2011-10-06 18:34:06) ======

No. Looks like the aliens have to *see* the corpse.
====== aduke1 (2011-10-06 19:30:28) ======

Ok, I have a theory:
The 'Retry' will initialize the game eg. create new LEs. But it does not purge the event queue or at least remove leftover events from the previous skirmish. Once the Init() is complete, the processing of events will continue with some old events that now point into the void.
Is something like that possible ?
====== tlh2000 (2011-10-06 20:15:47) ======

this is done - see CL_ClearBattlescapeEvents
====== aduke1 (2011-10-06 20:48:40) ======

I reproduced the crash with a debug exe. Output:
...
2011/10/06 20:31:31 ah has taken control over team 1.
2011/10/06 20:31:43 number | entnum | type | inuse | invis | pnum | team | size | HP | state | level | model/ptl
2011/10/06 20:31:43 ********************
2011/10/06 20:31:43 ERROR: LE_NotFoundError: Could ...
...

Provided LE_List_f works correctly, the above tells me that there are NO LEs at all. So how can there be an event related to an LE ??
Maybe CL_ClearBattlescapeEvents is not called at the right point in time ?

Is there any chance we can identify the offending event (eg. printing it) as 'outdated' ?

====== tlh2000 (2011-10-15 06:55:27) ======

@aduke what is your crashdump.txt saying which function it was?
====== tlh2000 (2011-10-16 07:46:03) ======

test map for easy reproducing
====== tlh2000 (2011-10-16 08:05:00) ======

game_go is the command that is executed on retry
====== tlh2000 (2011-10-16 08:05:36) ======

ufoconsole.log with setdeveloper DEBUG_EVENTSYS
====== tlh2000 (2011-10-16 08:16:01) ======

it looks like the attached ufoconsole.log revealed the problem

the eventTime for the EV_INV_ADD is less than the EV_ACTOR_APPEAR events after the retry. It is fine for the first run.
====== tlh2000 (2011-10-16 08:29:12) ======

the bug must be somewhere in the unreadable function CL_GetEventTime
====== tlh2000 (2011-10-16 08:29:58) ======

commenting this out:

else if (impactTime > cl.time) { /* item thrown on the ground */
eventTime = impactTime + 75;
}

does "fix" it. but there is a long waiting period that i did not yet come by
====== tlh2000 (2011-10-16 08:39:16) ======

----- first try --------------

2011/10/16 10:36:15 event(now): EV_RESET
2011/10/16 10:36:15 (player 0) It's team 1's turn!
2011/10/16 10:36:15 EV_ACTOR_APPEAR => eventTime: 26981, nextTime: 26981, impactTime: 26981, shootTime: 0
2011/10/16 10:36:15 event(at 26981): EV_ACTOR_APPEAR 0x19678be8
2011/10/16 10:36:15 EV_ACTOR_APPEAR => eventTime: 26981, nextTime: 26981, impactTime: 26981, shootTime: 0
2011/10/16 10:36:15 event(at 26981): EV_ACTOR_APPEAR 0x1b0e7408
2011/10/16 10:36:15 EV_ACTOR_APPEAR => eventTime: 26981, nextTime: 26981, impactTime: 26981, shootTime: 0
2011/10/16 10:36:15 event(at 26981): EV_ACTOR_APPEAR 0x1b98db38
2011/10/16 10:36:15 EV_ACTOR_APPEAR => eventTime: 26981, nextTime: 26981, impactTime: 26981, shootTime: 0
2011/10/16 10:36:15 event(at 26981): EV_ACTOR_APPEAR 0x1b98dbc8
2011/10/16 10:36:15 EV_ACTOR_STATECHANGE => eventTime: 26981, nextTime: 26981, impactTime: 26981, shootTime: 0
2011/10/16 10:36:15 event(at 26981): EV_ACTOR_STATECHANGE 0x1b0e3bc8
2011/10/16 10:36:15 EV_INV_ADD => eventTime: 26981, nextTime: 26981, impactTime: 26981, shootTime: 0
2011/10/16 10:36:15 event(at 26981): EV_INV_ADD 0x1b0e4de8


---- snap after retry ----

2011/10/16 10:36:51 event(now): EV_RESET
2011/10/16 10:36:51 (player 0) It's team 1's turn!
2011/10/16 10:36:51 EV_ACTOR_APPEAR => eventTime: 86109, nextTime: 86109, impactTime: 84709, shootTime: 84634
2011/10/16 10:36:51 event(at 86109): EV_ACTOR_APPEAR 0xa0d5148
2011/10/16 10:36:51 EV_ACTOR_APPEAR => eventTime: 86109, nextTime: 86109, impactTime: 84709, shootTime: 84634
2011/10/16 10:36:51 event(at 86109): EV_ACTOR_APPEAR 0x21a97ba8
2011/10/16 10:36:51 EV_ACTOR_APPEAR => eventTime: 86109, nextTime: 86109, impactTime: 84709, shootTime: 84634
2011/10/16 10:36:51 event(at 86109): EV_ACTOR_APPEAR 0x210de558
2011/10/16 10:36:51 EV_ACTOR_APPEAR => eventTime: 86109, nextTime: 86109, impactTime: 84709, shootTime: 84634
2011/10/16 10:36:51 event(at 86109): EV_ACTOR_APPEAR 0x210df778
2011/10/16 10:36:51 EV_ACTOR_STATECHANGE => eventTime: 86109, nextTime: 86109, impactTime: 84709, shootTime: 84634
2011/10/16 10:36:51 event(at 86109): EV_ACTOR_STATECHANGE 0x210e0998
2011/10/16 10:36:51 EV_INV_ADD => eventTime: 85109, nextTime: 86109, impactTime: 84709, shootTime: 84634
2011/10/16 10:36:51 event(at 85109): EV_INV_ADD 0x210e1bb8

====== tlh2000 (2011-10-16 08:40:47) ======

the delay between EV_RESET and the first other event must be bigger in the second case
====== tlh2000 (2011-10-16 09:17:11) ======

fixed in 80db4532727bfb27cb9342af7a3587d7ab8f80a5

the reason were the not reset static timer variables
====== aduke1 (2012-09-17 20:40:56.050000) ======

- **status**: pending --> closed