View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0000375 | LDMud 3.3 | Runtime | public | 2005-03-17 22:42 | 2018-01-29 21:57 |
Reporter | Assigned To | Gnomi | |||
Priority | normal | Severity | minor | Reproducibility | always |
Status | resolved | Resolution | fixed | ||
Target Version | 3.3.719 | Fixed in Version | 3.3.719 | ||
Summary | 0000375: call_out() timing is incorrect | ||||
Description | Assuming an alarm interval of 2: a call_out("fun", 2) done from inside a heartbeat will have fun() executed inside the current backend cycle, and not the next. This behaviour is caused by the fact that the call_out timing is based on relative delays, instead of being tied directly to the current time. On the other hand, some old code exploits this behaviour to have functions execute after the current player commands, but before the next. | ||||
Additional Information | The basic problem can be solved by storing absolute execution times into the call_out list; but I don't see any way to preserve the old code behavior in this. | ||||
Tags | No tags attached. | ||||
Attached Files | bug375.diff (5,020 bytes)
Index: trunk/test/t-0000375.c =================================================================== --- trunk/test/t-0000375.c (Revision 0) +++ trunk/test/t-0000375.c (Revision 0) @@ -0,0 +1,78 @@ +#include "/inc/base.inc" + +/* These functions are for the clone (the player object). */ +void start_client() +{ + net_connect("127.0.0.1", query_mud_port()); + set_heart_beat(1); +} + +int logon(int flag) +{ + enable_telnet(0); + set_prompt(""); + + return 1; +} + +object connect() +{ + enable_telnet(0); + set_prompt(""); + + return clone_object(this_object()); +} + +void fun(int* oldtime) +{ + int* now = utime(); + + remove_call_out(#'shutdown); + + // Is there a time difference of + // at least 0.5 seconds? + if (oldtime[1] < 500000) + oldtime[1] += 500000; + else + { + oldtime[1] -= 500000; + oldtime[0] += 1; + } + + if ((oldtime[0] == now[0]) + ?(oldtime[1] < now[1]) + :(oldtime[0] < now[0])) + shutdown(0); + else + shutdown(1); +} + +void heart_beat() +{ + call_out("fun", __ALARM_TIME__, utime()); +} + +void run_test() +{ + int result; + + msg("\nRunning test for #0000375:\n" + "--------------------------\n"); + + call_out("run_test2", 0); +} + +void run_test2() +{ + object dummy; + dummy = clone_object(this_object()); + dummy->start_client(); + + call_out(#'shutdown, (__HEART_BEAT_INTERVAL__+__ALARM_TIME__)*2, 1); // Just to make sure. +} + +string *epilog(int eflag) +{ + run_test(); + return 0; +} Index: trunk/src/call_out.c =================================================================== --- trunk/src/call_out.c (Revision 2592) +++ trunk/src/call_out.c (Arbeitskopie) @@ -216,28 +216,19 @@ return sp; } /* v_call_out() */ + /*-------------------------------------------------------------------------*/ void -call_out (void) +next_call_out_cycle (void) -/* Check if there is any callout due to be called. If yes, do so. - * This function is called from the heart_beat handling in the backend.c. - * It sets up its own error recovery context so that errors during an - * execution won't disturb the rest of the game. +/* Starts the next call_out cycle by decrementing the first delta. + * This function is called in the backend cycle before heart_beats are handled. */ { static int last_time; /* Last time this function was called */ - static struct call *current_call_out; - /* Current callout, static so that longjmp() won't clobber it. */ - - static object_t *called_object; - /* Object last called, static so that longjmp() won't clobber it */ - - struct error_recovery_info error_recovery_info; - /* No calls pending: just update the last_time and return */ if (call_list == NULL) @@ -250,12 +241,38 @@ if (last_time == 0) last_time = current_time; - /* Update the first .delta in the list (so it won't happen - * twice in case of an error. + /* Update the first .delta in the list. */ call_list->delta -= current_time - last_time; last_time = current_time; +} /* next_call_out_cycle() */ + + +/*-------------------------------------------------------------------------*/ +void +call_out (void) + +/* Check if there is any callout due to be called. If yes, do so. + * This function is called from the heart_beat handling in the backend.c. + * It sets up its own error recovery context so that errors during an + * execution won't disturb the rest of the game. + */ + +{ + static struct call *current_call_out; + /* Current callout, static so that longjmp() won't clobber it. */ + + static object_t *called_object; + /* Object last called, static so that longjmp() won't clobber it */ + + struct error_recovery_info error_recovery_info; + + /* No calls pending: fine. */ + + if (call_list == NULL) + return; + current_interactive = NULL; /* Activate the local error recovery context */ Index: trunk/src/call_out.h =================================================================== --- trunk/src/call_out.h (Revision 2592) +++ trunk/src/call_out.h (Arbeitskopie) @@ -8,6 +8,7 @@ /* --- Prototypes --- */ extern void call_out(void); +extern void next_call_out_cycle(void); extern size_t call_out_status(strbuf_t *sbuf, Bool verbose); extern void callout_dinfo_status(svalue_t *svp, int value); extern void remove_stale_call_outs(void); Index: trunk/src/backend.c =================================================================== --- trunk/src/backend.c (Revision 2592) +++ trunk/src/backend.c (Arbeitskopie) @@ -717,6 +717,11 @@ time_to_call_heart_beat = MY_FALSE; alarm(alarm_time); + /* So call_outs from heart_beats are + * correctly timed. + */ + next_call_out_cycle(); + /* Do the timed events */ if (!synch_heart_beats || time_of_last_hb + heart_beat_interval <= current_time) | ||||
|
Iirc we use call_out("fun",0) to achieve the goal of putting the call_out behind the current commands and just before the next ones. Main reason for this is resetting evals for some expensive operations. But I may wrong here. |
|
call_out chains for preventing 'too long eval' is standard behaviour, yes. I suggest, if we change the timing behaviour, we should do it in 3.5.x. Any opinions, if we want to change it or declare it a feature...? |
|
I think the timing problem should be fixed in 3.5 (I wouldn't mind if we do it in 3.3). I don't see any problem with old code behavior: If you wan't the old behaviour you use call_out("fun",0). As for too long eval errors: When calling from a heart_beat you don't want the old behavior (heart_beat and call_outs from the same object share their eval count in each cycle). |
|
I thought to not force wizards to check and change their code between e.g. 3.3.719 and 3.3.720. Probably the code Lars described is rather rare. But I guess, very difficult to find. But I could ultimately also live with fixing it in 3.3. You are right concerning the eval costs. I meant call_out chains in general, not with a specific delay of 2 or 0, which are not a good idea, right. When we migrated from our old LP driver to LDMud 3.3 we had about 2-3 dozens call_out(...,0) in a call_out, which resulted in a callout chain with zero delay, was quite funny. ;-) |
|
I don't think, wizards have to check their code. If someone wanted that behavior of starting a call_out directly after a heart_beat he would have called call_out("fun", 0). If there's somewhere a call_out("fun", 2) from a heart_beat it almost never was meant to start directly after the heart_beat but 2 seconds later. That's why I don't think this bugfix would break code. |
|
I uploaded a patch that fixes this by starting the call_out cycle before heart_beats are handled (call_outs are not executed, but the first delay is decremented and last_time is updated, so it does correctly reflect the timing during the heart_beats). |
|
Looks good to me, I did not expect it to be that simple. :-) |
|
Committed as r2596. |
Date Modified | Username | Field | Change |
---|---|---|---|
2005-03-17 22:42 |
|
New Issue | |
2005-03-19 12:01 | peng | Note Added: 0000357 | |
2009-03-04 15:39 | zesstra | Note Added: 0000973 | |
2009-03-04 15:39 | zesstra | Status | new => confirmed |
2009-03-04 15:39 | zesstra | Project | LDMud => LDMud 3.5 |
2009-03-04 16:14 | Gnomi | Note Added: 0000976 | |
2009-03-04 16:52 | zesstra | Note Added: 0000979 | |
2009-05-20 15:31 | Gnomi | Note Added: 0001125 | |
2009-05-20 15:31 | Gnomi | Assigned To | => Gnomi |
2009-05-20 15:31 | Gnomi | Product Version | 3.3 => |
2009-05-21 04:58 | Gnomi | Note Edited: 0001125 | |
2009-05-26 12:17 | Gnomi | File Added: bug375.diff | |
2009-05-26 12:19 | Gnomi | Note Added: 0001164 | |
2009-05-26 12:20 | Gnomi | Project | LDMud 3.5 => LDMud 3.3 |
2009-05-26 12:20 | Gnomi | Target Version | => 3.3.719 |
2009-05-26 15:28 | zesstra | Note Added: 0001166 | |
2009-05-27 12:24 | Gnomi | Note Added: 0001169 | |
2009-05-27 12:24 | Gnomi | Status | confirmed => resolved |
2009-05-27 12:24 | Gnomi | Fixed in Version | => 3.3.719 |
2009-05-27 12:24 | Gnomi | Resolution | open => fixed |
2010-11-16 09:42 | Gnomi | Source_changeset_attached | => ldmud.git master a1e7d333 |
2018-01-29 18:59 | Gnomi | Source_changeset_attached | => ldmud.git master a1e7d333 |
2018-01-29 21:57 | Gnomi | Source_changeset_attached | => ldmud.git master a1e7d333 |