Issue Information
-
#001640
-
5 - Critical
-
Fixed
Issue Confirmations
-
Yes (3)No (0)
0
Originally posted by Dzugaru
http://www.eathena.w...er&showbug=1640
Ok, now it occured on 2 maps already. in_sphinx5 suddenly stopped spawning anything except 7 mimics and pharaon
in_sphinx5,0,0,0,0 monster Pasana 1154,70,0,0,0
in_sphinx5,0,0,0,0 monster Matyr 1146,10,0,0,0
in_sphinx5,0,0,0,0 monster Side Winder 1037,20,0,0,0
in_sphinx5,0,0,0,0 monster Anubis 1098,10,0,0,0
in_sphinx5,0,0,0,0 monster Mimic 1191,7,600000,300000,1
in_sphinx5,0,0,0,0 monster Pharaoh 1157,1,3600000,1800000,1
and on gef_fild13 there are only 3 creamies left
gef_fild13,0,0,0,0 monster Poporing 1031,20,0,0,0
gef_fild13,0,0,0,0 monster Creamy 1018,40,0,0,0
gef_fild13,0,0,0,0 monster Ambernite 1094,30,0,0,0
Mobs that left respawn normally after 5 secs after being killed. I'm using dynamic mobs caching (5min removing timer), and recenlty enabled battle_config.etc_log, but strangely when I'm leaving the gef_fild13 (and noone there left for 5 mins I'm sure of it) - console do not write about mobs (3 creamies) removed, that means timer is bugged (really strange), or mobs (with 0 = delay1 = delay2) somehow not being marked as dynamically cached anymore. I've checked the gettick() and its ~1500000000, so it cant be a timer looping bug or something like this.
And the strangest thing is - recently all mobs appeared (all 90), but after some time - just 3 creamies left again. The server runs on 64bit SuSe 10.3. I'll inform you about the futher investigation.
http://www.eathena.w...er&showbug=1640
Ok, now it occured on 2 maps already. in_sphinx5 suddenly stopped spawning anything except 7 mimics and pharaon
in_sphinx5,0,0,0,0 monster Pasana 1154,70,0,0,0
in_sphinx5,0,0,0,0 monster Matyr 1146,10,0,0,0
in_sphinx5,0,0,0,0 monster Side Winder 1037,20,0,0,0
in_sphinx5,0,0,0,0 monster Anubis 1098,10,0,0,0
in_sphinx5,0,0,0,0 monster Mimic 1191,7,600000,300000,1
in_sphinx5,0,0,0,0 monster Pharaoh 1157,1,3600000,1800000,1
and on gef_fild13 there are only 3 creamies left
gef_fild13,0,0,0,0 monster Poporing 1031,20,0,0,0
gef_fild13,0,0,0,0 monster Creamy 1018,40,0,0,0
gef_fild13,0,0,0,0 monster Ambernite 1094,30,0,0,0
Mobs that left respawn normally after 5 secs after being killed. I'm using dynamic mobs caching (5min removing timer), and recenlty enabled battle_config.etc_log, but strangely when I'm leaving the gef_fild13 (and noone there left for 5 mins I'm sure of it) - console do not write about mobs (3 creamies) removed, that means timer is bugged (really strange), or mobs (with 0 = delay1 = delay2) somehow not being marked as dynamically cached anymore. I've checked the gettick() and its ~1500000000, so it cant be a timer looping bug or something like this.
And the strangest thing is - recently all mobs appeared (all 90), but after some time - just 3 creamies left again. The server runs on 64bit SuSe 10.3. I'll inform you about the futher investigation.
Originally posted by Gepard
Temporary code to track and prevent the multiple remove_map's was added in [rev=12430].
Issue is most likely still present in rAthena. Here are some debug messages produced by the tracking code:
I'd appreciate rA server owners to check their logs for similar debug messages, to make sure problem is not fixed yet.
Temporary code to track and prevent the multiple remove_map's was added in [rev=12430].
Issue is most likely still present in rAthena. Here are some debug messages produced by the tracking code:
[26/Jun 12:29:49][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000158/150444 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=prtg_cas01 (users=0). Previous call from unit.c:2227(unit_remove_map_pc), current call from unit.c:2227(unit_remove_map_pc). Please report this!!! [29/Jun 13:41:44][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000011/150075 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=prtg_cas01 (users=2). Previous call from unit.c:2227(unit_remove_map_pc), current call from unit.c:2227(unit_remove_map_pc). Please report this!!! [08/Oct 20:37:00][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000592/158475 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=mag_dun01 (users=0). Previous call from unit.c:2286(unit_remove_map_pc), current call from unit.c:2286(unit_remove_map_pc). Please report this!!!
[26/Jan 20:59:35][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2007392/180436 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas02 (users=17). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!! [06/Mar 21:03:52][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000463/172923 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=schg_cas01 (users=30). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!!
[05/Jan 20:55:19][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2006297/209881 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas03 (users=11). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!! [12/Jan 20:46:44][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002578/227330 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas03 (users=15). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!! [26/Jan 20:47:11][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2004446/172382 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas03 (users=4). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!! [02/Mar 20:18:27][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002578/227330 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas05 (users=10). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!! [05/Mar 20:51:50][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2003809/224965 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas05 (users=15). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!! [09/Mar 20:07:14][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2022485/230123 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas05 (users=13). Previous call from unit.c:1943(unit_remove_map_pc), current call from unit.c:1943(unit_remove_map_pc). Please report this!!! [06/Apr 20:03:29][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000229/150163 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=pay_fild03 (users=0). Previous call from unit.c:2014(unit_remove_map_pc), current call from unit.c:2014(unit_remove_map_pc). Please report this!!! [09/Apr 20:40:31][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2021795/227366 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=prtg_cas01 (users=12). Previous call from unit.c:2014(unit_remove_map_pc), current call from unit.c:2014(unit_remove_map_pc). Please report this!!! [10/Apr 20:10:20][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2022324/229452 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=in_sphinx3 (users=0). Previous call from unit.c:2014(unit_remove_map_pc), current call from unit.c:2014(unit_remove_map_pc). Please report this!!! [10/May 19:38:42][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2006321/232445 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=pay_arche (users=0). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [04/Jun 20:05:03][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2010194/185757 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=8). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [13/Jun 18:56:35][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2023277/233222 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=in_sphinx3 (users=0). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [09/Jul 20:25:44][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2013450/197688 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=5). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [20/Jul 20:54:48][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000987/220441 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=20). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [17/Aug 20:36:33][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2022730/231056 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=7). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [21/Aug 13:28:16][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2019266/218257 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=in_sphinx3 (users=0). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [31/Aug 20:39:47][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2006994/174605 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=9). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [14/Sep 20:36:52][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2022730/231056 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=8). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [21/Sep 20:06:01][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2022730/231056 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=7). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [25/Oct 20:37:15][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2022875/233171 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=lhz_dun02 (users=0). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [26/Oct 20:06:44][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2024132/236129 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=10). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [12/Nov 20:03:26][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2020577/222888 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=gef_fild13 (users=2). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [03/Dec 20:28:53][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2024440/236963 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=3). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!! [04/Jan 20:08:48][Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000745/236495 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=gefg_cas04 (users=14). Previous call from unit.c:2017(unit_remove_map_pc), current call from unit.c:2017(unit_remove_map_pc). Please report this!!!
I'd appreciate rA server owners to check their logs for similar debug messages, to make sure problem is not fixed yet.
Originally posted by Gepard
Another bug about the same issue, with some info that could be helpful: [bug=1279] (http://www.eathena.w...er&showbug=1279)
eAthena Support Board -> Bug Tracker -> eAthena -> Unit_remove_map Debug
Posted by: Ai4rei on Mar 26 2008, 08:47 PM
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002585/163279 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=2). Please report this!!!
Posted by: Ai4rei on Mar 30 2008, 11:41 AM
Another one occured.
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002573/163399 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=anthell01 (users=0). Please report this!!!
Posted by: Slennox on Mar 30 2008, 04:33 PM
Testing revision 12430 with FlavioJS' debug code:
QUOTE
<%CIA-1> eAthena: 03FlavioJS * r12430 10/trunk/src/map/ (clif.c pc.h unit.c): * Added temporary code to track and prevent the multiple remove_map's that appear to be happening.
<[Blue]> hmmm
<DaIRC36694> Slennox, update and try this version
<DaIRC36694> make sure you log the console
<DaIRC36694> (debug info)
<DaIRC36694> night all
<DaIRC36694> oh ups
03* DaIRC36694 is now known as flaviojs
12* Akira sets mode: +o flaviojs
01<Slennox> thank you flaviojs, we'll try them tomorrow and report back during the week
After one week and a WoE disputed (400 ppl server):
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2001708/451 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=73). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002032/304 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=pay_gld (users=22). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002316/495 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=113). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000092/1156 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=76). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2003577/3753 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=c_tower2 (users=0). Please report this!!!
This is very bad, it's happening in WoE maps
The WoE script seemed broken by the way, it didn't always respawn people out of the castle... but we don't know if it's related to that problem.
I have the full console server log in a file. If you need to search for other Debug messages I'll grep'em for you
Sle
Posted by: flaviojs on Apr 7 2008, 01:58 PM
Forgot to mention here, more debug information was added in r12457/r12458.
Please update to r12458+ and report the extended message, thank you.
Posted by: Ai4rei on Apr 16 2008, 07:55 PM
Occured during WoE:
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002573/163427 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=5). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002533/162788 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=6). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
map/unit.c:1821:
CODE
void unit_remove_map_pc(struct map_session_data *sd, int clrtype)
{
unit_remove_map(&sd->bl,clrtype); // <-- line 1821
if (clrtype == 3) clrtype = 0; //3 is the warp from logging out, but pets/homunc need to just 'vanish' instead of showing the warping out animation.
if(sd->pd)
unit_remove_map(&sd->pd->bl, clrtype);
if(merc_is_hom_active(sd->hd))
unit_remove_map(&sd->hd->bl, clrtype);
}
Posted by: Ai4rei on May 1 2008, 09:58 AM
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002623/162345 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=alde_gld (users=2). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002623/162345 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=aldeg_cas01 (users=1). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
Once again during WoE. For code-position, see previous post.
Posted by: Ai4rei on May 22 2008, 02:30 AM
I did a further extension of the debug message by myself, to figure out, what is calling unit_remove_map_pc. It turns out, that it is called from the same position in pc_setpos.
/src/map/pc.c:3609 (r12718)
CODE
if( x < 0 || x >= map[m].xs || y < 0 || y >= map[m].ys )
{
ShowError("pc_setpos: attempt to place player %s (%d:%d) on invalid coordinates (%s-%d,%d)\n", sd->status.name, sd->status.account_id, sd->status.char_id, mapindex_id2name(mapindex),x,y);
x = y = 0; // make it random
}
if( x == 0 && y == 0 )
{// pick a random walkable cell
do {
x=rand()%(map[m].xs-2)+1;
y=rand()%(map[m].ys-2)+1;
} while(map_getcell(m,x,y,CELL_CHKNOPASS));
}
if(sd->bl.prev != NULL){
unit_remove_map_pc(sd,clrtype); // <-- Prev & current call [line:3609]
clif_changemap(sd,map[m].index,x,y); // [MouseJstr]
} else if(sd->state.active)
//Tag player for rewarping after map-loading is done. [Skotlex]
sd->state.rewarp = 1;
Posted by: Ai4rei on Jun 10 2008, 06:04 AM
Once again digging this up, still cannot reproduce it intentionally, but could further track where both calls are coming from. Both calls start in unit_walktoxy_timer and go along through npc_touch_areanpc->pc_setpos->unit_remove_map_pc->unit_remove_map.
/src/map/unit.c (r127xx):
CODE
static int unit_walktoxy_timer(int tid, unsigned int tick, int id, intptr data)
{
[...]
if(sd) {
if(map_getcell(bl->m,x,y,CELL_CHKNPC)) {
npc_touch_areanpc(sd,bl->m,x,y); // <--
if (bl->prev == NULL) //Script could have warped char, abort remaining of the function.
return 0;
} else
sd->areanpc_id=0;
if (sd->state.gmaster_flag &&
(battle_config.guild_aura&(agit_flag?2:1)) &&
(battle_config.guild_aura&(map_flag_gvg2(bl->m)?8:4))
)
Dunno how to track it further, hope this may help.
Another bug about the same issue, with some info that could be helpful: [bug=1279] (http://www.eathena.w...er&showbug=1279)
eAthena Support Board -> Bug Tracker -> eAthena -> Unit_remove_map Debug
Posted by: Ai4rei on Mar 26 2008, 08:47 PM
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002585/163279 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=2). Please report this!!!
Posted by: Ai4rei on Mar 30 2008, 11:41 AM
Another one occured.
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002573/163399 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=anthell01 (users=0). Please report this!!!
Posted by: Slennox on Mar 30 2008, 04:33 PM
Testing revision 12430 with FlavioJS' debug code:
QUOTE
<%CIA-1> eAthena: 03FlavioJS * r12430 10/trunk/src/map/ (clif.c pc.h unit.c): * Added temporary code to track and prevent the multiple remove_map's that appear to be happening.
<[Blue]> hmmm
<DaIRC36694> Slennox, update and try this version
<DaIRC36694> make sure you log the console
<DaIRC36694> (debug info)
<DaIRC36694> night all
<DaIRC36694> oh ups
03* DaIRC36694 is now known as flaviojs
12* Akira sets mode: +o flaviojs
01<Slennox> thank you flaviojs, we'll try them tomorrow and report back during the week
After one week and a WoE disputed (400 ppl server):
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2001708/451 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=73). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002032/304 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=pay_gld (users=22). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002316/495 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=113). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2000092/1156 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=76). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2003577/3753 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=c_tower2 (users=0). Please report this!!!
This is very bad, it's happening in WoE maps
The WoE script seemed broken by the way, it didn't always respawn people out of the castle... but we don't know if it's related to that problem.I have the full console server log in a file. If you need to search for other Debug messages I'll grep'em for you
Sle
Posted by: flaviojs on Apr 7 2008, 01:58 PM
Forgot to mention here, more debug information was added in r12457/r12458.
Please update to r12458+ and report the extended message, thank you.
Posted by: Ai4rei on Apr 16 2008, 07:55 PM
Occured during WoE:
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002573/163427 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=5). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002533/162788 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=payg_cas03 (users=6). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
map/unit.c:1821:
CODE
void unit_remove_map_pc(struct map_session_data *sd, int clrtype)
{
unit_remove_map(&sd->bl,clrtype); // <-- line 1821
if (clrtype == 3) clrtype = 0; //3 is the warp from logging out, but pets/homunc need to just 'vanish' instead of showing the warping out animation.
if(sd->pd)
unit_remove_map(&sd->pd->bl, clrtype);
if(merc_is_hom_active(sd->hd))
unit_remove_map(&sd->hd->bl, clrtype);
}
Posted by: Ai4rei on May 1 2008, 09:58 AM
CODE
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002623/162345 (active=1 connect_new=0 rewarp=0 changemap=1 debug_remove_map=1) from map=alde_gld (users=2). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
[Debug]: unit_remove_map: unexpected state when removing player AID/CID:2002623/162345 (active=1 connect_new=0 rewarp=0 changemap=0 debug_remove_map=1) from map=aldeg_cas01 (users=1). Previous call from ..\src\map\unit.c:1821(unit_remove_map_pc), current call from ..\src\map\unit.c:1821(unit_remove_map_pc). Please report this!!!
Once again during WoE. For code-position, see previous post.
Posted by: Ai4rei on May 22 2008, 02:30 AM
I did a further extension of the debug message by myself, to figure out, what is calling unit_remove_map_pc. It turns out, that it is called from the same position in pc_setpos.
/src/map/pc.c:3609 (r12718)
CODE
if( x < 0 || x >= map[m].xs || y < 0 || y >= map[m].ys )
{
ShowError("pc_setpos: attempt to place player %s (%d:%d) on invalid coordinates (%s-%d,%d)\n", sd->status.name, sd->status.account_id, sd->status.char_id, mapindex_id2name(mapindex),x,y);
x = y = 0; // make it random
}
if( x == 0 && y == 0 )
{// pick a random walkable cell
do {
x=rand()%(map[m].xs-2)+1;
y=rand()%(map[m].ys-2)+1;
} while(map_getcell(m,x,y,CELL_CHKNOPASS));
}
if(sd->bl.prev != NULL){
unit_remove_map_pc(sd,clrtype); // <-- Prev & current call [line:3609]
clif_changemap(sd,map[m].index,x,y); // [MouseJstr]
} else if(sd->state.active)
//Tag player for rewarping after map-loading is done. [Skotlex]
sd->state.rewarp = 1;
Posted by: Ai4rei on Jun 10 2008, 06:04 AM
Once again digging this up, still cannot reproduce it intentionally, but could further track where both calls are coming from. Both calls start in unit_walktoxy_timer and go along through npc_touch_areanpc->pc_setpos->unit_remove_map_pc->unit_remove_map.
/src/map/unit.c (r127xx):
CODE
static int unit_walktoxy_timer(int tid, unsigned int tick, int id, intptr data)
{
[...]
if(sd) {
if(map_getcell(bl->m,x,y,CELL_CHKNPC)) {
npc_touch_areanpc(sd,bl->m,x,y); // <--
if (bl->prev == NULL) //Script could have warped char, abort remaining of the function.
return 0;
} else
sd->areanpc_id=0;
if (sd->state.gmaster_flag &&
(battle_config.guild_aura&(agit_flag?2:1)) &&
(battle_config.guild_aura&(map_flag_gvg2(bl->m)?8:4))
)
Dunno how to track it further, hope this may help.
Originally posted by Ind
scary. I don't have much clue .-.
scary. I don't have much clue .-.
Originally posted by Wildcard
How to reproduce
1) Cast AL_WARP (warp portal) on the very edge of a warp area_npc. The destination is of no importance.
2) Wait for the portal to become active.
3) Use cloaking.
4) Walk to the tile with the warp portal (and warp npc).
(this can be done with two characters by "legitimate" players.)
Reconstruction
As the character arrives at the destination tile, warp portal will trigger. It is important to note that this happens despite being in cloaking state. The issuing map change will end the cloaking state. Ending cloaking will in turn trigger nearby area npcs, thus activating a second warp inside the code of the first. Thus unit_remove_map will re-enter and print the warning/double decrement the map user counter. The character will arrive at the second destination, while the first will receive the faulty user count.
Stacktrace
The first call to unit_remove_map. Note status_change_end in there.
And for completion's sake, this is the second call. Note that it's exactly the same call as the lower part of the first.
Proposed Solution
This is a delicate issue, and I'm afraid I'm not too familiar with the inner workings of the unit code as of yet. My initial instinct was to end the statuses after map change instead of before, but the number of scenarios (especially pc vs non-pc) and potential side effects are huge. For one, the client would no longer properly display the character uncloaking when doing so on top of a warp. My second idea would involve making non-re-entrant version of status_change_end. I'm sure a better solution exists, however, and will see if I can come up with one. If you have any input, please share it! I hope I was of help.
Additional Concerns
It is entirely possible that other scenarios exist for the same issue. I sifted though most of the code surrounding it, but was unable to spot anything at first glance.
Regards,
Wildcard
How to reproduce
1) Cast AL_WARP (warp portal) on the very edge of a warp area_npc. The destination is of no importance.
2) Wait for the portal to become active.
3) Use cloaking.
4) Walk to the tile with the warp portal (and warp npc).
(this can be done with two characters by "legitimate" players.)
Reconstruction
As the character arrives at the destination tile, warp portal will trigger. It is important to note that this happens despite being in cloaking state. The issuing map change will end the cloaking state. Ending cloaking will in turn trigger nearby area npcs, thus activating a second warp inside the code of the first. Thus unit_remove_map will re-enter and print the warning/double decrement the map user counter. The character will arrive at the second destination, while the first will receive the faulty user count.
Stacktrace
The first call to unit_remove_map. Note status_change_end in there.
> map-server_sql.exe!unit_remove_map_(block_list * bl=0x0b5ed290, clr_type clrtype=CLR_OUTSIGHT, const char * file=0x007d3d84, int line=2133, const char * func=0x007ac11a) Line 2049 C map-server_sql.exe!unit_remove_map_pc(map_session_data * sd=0x0b5ed290, clr_type clrtype=CLR_OUTSIGHT) Line 2133 + 0x20 bytes C map-server_sql.exe!pc_setpos(map_session_data * sd=0x0b5ed290, unsigned short mapindex=108, int x=299, int y=170, clr_type clrtype=CLR_OUTSIGHT) Line 4380 + 0xd bytes C map-server_sql.exe!npc_touch_areanpc(map_session_data * sd=0x0b5ed290, int m=160, int x=15, int y=152) Line 913 + 0x5c bytes C map-server_sql.exe!status_change_end_(block_list * bl=0x0b5ed290, sc_type type=SC_CLOAKING, int tid=-1, const char * file=0x007d3d84, int line=1985) Line 8387 + 0x21 bytes C map-server_sql.exe!unit_remove_map_(block_list * bl=0x0b5ed290, clr_type clrtype=CLR_TELEPORT, const char * file=0x007d3d84, int line=2133, const char * func=0x007ac11a) Line 1985 + 0x1b bytes C map-server_sql.exe!unit_remove_map_pc(map_session_data * sd=0x0b5ed290, clr_type clrtype=CLR_TELEPORT) Line 2133 + 0x20 bytes C map-server_sql.exe!pc_setpos(map_session_data * sd=0x0b5ed290, unsigned short mapindex=136, int x=53, int y=111, clr_type clrtype=CLR_TELEPORT) Line 4380 + 0xd bytes C map-server_sql.exe!skill_unit_onplace(skill_unit * src=0x0f4ec64c, block_list * bl=0x0b5ed290, unsigned int tick=14509615) Line 9319 + 0x1b bytes C map-server_sql.exe!skill_unit_move_sub(block_list * bl=0x0f4ec64c, char * ap=0x0018f970) Line 13172 + 0x11 bytes C map-server_sql.exe!map_foreachincell(int (block_list *, char *)* func=0x00537333, int m=160, int x=15, int y=152, int type=64, ...) Line 930 + 0x14 bytes C map-server_sql.exe!skill_unit_move(block_list * bl=0x0b5ed290, unsigned int tick=14509615, int flag=3) Line 13225 + 0x30 bytes C map-server_sql.exe!map_moveblock(block_list * bl=0x0b5ed290, int x1=15, int y1=152, unsigned int tick=14509615) Line 416 + 0xf bytes C map-server_sql.exe!unit_walktoxy_timer(int tid=60, unsigned int tick=14509615, int id=2000000, int data=135) Line 162 + 0x15 bytes C map-server_sql.exe!do_timer(unsigned int tick=14509668) Line 371 + 0x4a bytes C
And for completion's sake, this is the second call. Note that it's exactly the same call as the lower part of the first.
> map-server_sql.exe!unit_remove_map_(block_list * bl=0x0b5ed290, clr_type clrtype=CLR_TELEPORT, const char * file=0x007d3d84, int line=2133, const char * func=0x007ac11a) Line 2049 C map-server_sql.exe!unit_remove_map_pc(map_session_data * sd=0x0b5ed290, clr_type clrtype=CLR_TELEPORT) Line 2133 + 0x20 bytes C map-server_sql.exe!pc_setpos(map_session_data * sd=0x0b5ed290, unsigned short mapindex=136, int x=53, int y=111, clr_type clrtype=CLR_TELEPORT) Line 4380 + 0xd bytes C map-server_sql.exe!skill_unit_onplace(skill_unit * src=0x0f4ec64c, block_list * bl=0x0b5ed290, unsigned int tick=14509615) Line 9319 + 0x1b bytes C map-server_sql.exe!skill_unit_move_sub(block_list * bl=0x0f4ec64c, char * ap=0x0018f970) Line 13172 + 0x11 bytes C map-server_sql.exe!map_foreachincell(int (block_list *, char *)* func=0x00537333, int m=160, int x=15, int y=152, int type=64, ...) Line 930 + 0x14 bytes C map-server_sql.exe!skill_unit_move(block_list * bl=0x0b5ed290, unsigned int tick=14509615, int flag=3) Line 13225 + 0x30 bytes C map-server_sql.exe!map_moveblock(block_list * bl=0x0b5ed290, int x1=15, int y1=152, unsigned int tick=14509615) Line 416 + 0xf bytes C map-server_sql.exe!unit_walktoxy_timer(int tid=60, unsigned int tick=14509615, int id=2000000, int data=135) Line 162 + 0x15 bytes C map-server_sql.exe!do_timer(unsigned int tick=14509668) Line 371 + 0x4a bytes C
Proposed Solution
This is a delicate issue, and I'm afraid I'm not too familiar with the inner workings of the unit code as of yet. My initial instinct was to end the statuses after map change instead of before, but the number of scenarios (especially pc vs non-pc) and potential side effects are huge. For one, the client would no longer properly display the character uncloaking when doing so on top of a warp. My second idea would involve making non-re-entrant version of status_change_end. I'm sure a better solution exists, however, and will see if I can come up with one. If you have any input, please share it! I hope I was of help.
Additional Concerns
It is entirely possible that other scenarios exist for the same issue. I sifted though most of the code surrounding it, but was unable to spot anything at first glance.
Regards,
Wildcard
Edited by Wildcard, 14 February 2012 - 01:55 PM.
Originally posted by Cookie
After extensive testing, on and off my live server (400-500 players online) to ensure this fix won't affect anything else, I've come up with the following fix. Fixed in [rev=16434]. Not experiencing any issues with dynamic mobs not spawning due to the -1, as well.
Edit:
Not an end-all-be-all to the issue (in my opinion, as Wildcard pointed out), but it surely resolved the "unit_remove_map: unexpected state when removing player" jazz and issues with mobs not spawning (the original issue at hand).
After extensive testing, on and off my live server (400-500 players online) to ensure this fix won't affect anything else, I've come up with the following fix. Fixed in [rev=16434]. Not experiencing any issues with dynamic mobs not spawning due to the -1, as well.
Edit:
Not an end-all-be-all to the issue (in my opinion, as Wildcard pointed out), but it surely resolved the "unit_remove_map: unexpected state when removing player" jazz and issues with mobs not spawning (the original issue at hand).
