Crash Bug: DeleteTimer crash the MUSHClient

Posted by Wanghom8228 on Mon 14 Jun 2010 02:02 AM — 29 posts, 93,821 views.

Wanghom8228 Mon 14 Jun 2010 02:02 AM #0

Repro Step at MUSHClient 4.51:
1. Create a MCL with following alias & timer.


<aliases>
 <alias match="CT" enabled="y" send_to="12" sequence="100">
  <send>world.EnableTimer("tm_delete")
local name = "tm_test"
local seconds = 2
--local script = "test()"
  check (world.AddTimer (
      name, 
      0, 
      0, 
      seconds, 
      "",
      timer_flag.Enabled + timer_flag.OneShot + timer_flag.Temporary + timer_flag.Replace, 
      ""))  
</send>
  </alias>
</aliases>

<timers>
  <timer name="tm_delete" second="1.00" offset_second="0.00" send_to="12">
  <send>world.Note("timer")
world.DeleteTimer("tm_test")
--world.EnableTimer("tm_test", false)</send>
  </timer>
</timers>

2. Open the MCL and connect to the MUD game.
3. Type alias "CT".
4. The MUSHClient will crash.

It not always repro, but very easy. You might need to do the #3 quickly after connect to the game.

Twisol USA Mon 14 Jun 2010 02:06 AM #1

I don't see an alias TC (though you did post a CT, did you mean that?), and I don't see DeleteTimer() used anywhere at all.

Nick Gammon Australia Forum Administrator Mon 14 Jun 2010 04:47 AM #2

I can't reproduce this. Did you copy and paste the aliases directly?

For advice on how to copy aliases, timers or triggers from within MUSHclient, and paste them into a forum message, please see Copying XML.

I don't see this variable used anywhere:


local script = "test()"

The timer you add (called tm_test) doesn't seem to do anything.

Wanghom8228 Mon 14 Jun 2010 07:15 AM #3

My bad. I had some typo in the script. I have fixed it.
The crash happen in the DeleteTimer, but if i change the DeleteTimer to EnableTimer(false), it works fine.
It is my only workaround now.

Twisol USA Mon 14 Jun 2010 07:16 AM #4

DeleteTimer will delete a timer completely. EnableTimer("name", false) simply disables it, so it still exists but is inactive.

Wanghom8228 Mon 14 Jun 2010 07:16 AM #5

It doesn't matter where is "test()" function, since it is never expected to be executed. I just want to show a min repro to you guys.

Nick Gammon Australia Forum Administrator Mon 14 Jun 2010 11:24 AM #6

So in effect you are saying that if one timer deletes another, it crashes, is that it?

Wanghom8228 Mon 14 Jun 2010 12:34 PM #7

Yes. I think so.
BTW: Nick, can you repro it in your box? Is it a real bug? Or caused by my bad usage?

Twisol USA Mon 14 Jun 2010 06:43 PM #8

I tried setting up two timers and having one delete the other. No crash here. I'm using a custom build of 4.52,, but I haven't really changed any functionality.

Nick Gammon Australia Forum Administrator Mon 14 Jun 2010 09:53 PM #9

There is a test in the timer code that you cannot delete a timer (delete itself) whilst a script is running. This is probably because deleting something while it is executing is a bad idea (the pointer to the timer script becomes invalid while the script is running).

Although you are not doing that, it is possible that a timer that deletes another timer could cause a crash, as it may modify the list of timers that it is currently traversing (in other words, you may remove the item from the list that is about to be tested).

You may also defeat the internal test by having one timer call a script which causes a different timer to delete the first one (somehow, I can't quite get my head around that one).

You could explore using EnableTimer (timername, false) to simply disable it, or use one-shot timers which self-delete at a safe time (although even that looks slighly dubious, looking at the code).

Twisol, in doc.cpp around line 4448, is the code that goes through timers:


  for (POSITION pos = TimerMap.GetStartPosition(); pos; )
    {
    TimerMap.GetNextAssoc (pos, strTimerName, timer_item);

I'm not sure how reliable the GetNextAssoc is, if the map changes (ie. a timer is deleted elsewhere, like in a script). Effectively, pos could become invalid, as far as I can see.

Nick Gammon Australia Forum Administrator Mon 14 Jun 2010 09:53 PM #10

Wanghom8228 said:

Yes. I think so.
BTW: Nick, can you repro it in your box? Is it a real bug? Or caused by my bad usage?

I haven't reproduced it yet.

Twisol USA Mon 14 Jun 2010 11:16 PM #11

Nick Gammon said:
Twisol, in doc.cpp around line 4448, is the code that goes through timers:


  for (POSITION pos = TimerMap.GetStartPosition(); pos; )
    {
    TimerMap.GetNextAssoc (pos, strTimerName, timer_item);

I'm not sure how reliable the GetNextAssoc is, if the map changes (ie. a timer is deleted elsewhere, like in a script). Effectively, pos could become invalid, as far as I can see.

That's an interesting point. I don't know what CTypedPtrMap (or CMapStringToPtr I suppose) uses internally, but if it uses a linked list it should be immune (as long as you don't remove the current one).

Hrm. While timers just have a single map definition (CTimerMap), aliases and triggers seem to have array and list typedefs as well. I understand that the array is used for sequencing, which timers don't need, but then there's the list. I assume the list exists precisely to avoid these issues, because as long as you don't remove the current item, it's safe. Array iterators will be invalidated if you remove anything before the current position, in the best case.

Wanghom8228 Mon 14 Jun 2010 11:18 PM #12

Nick Gammon said:

There is a test in the timer code that you cannot delete a timer (delete itself) whilst a script is running. This is probably because deleting something while it is executing is a bad idea (the pointer to the timer script becomes invalid while the script is running).

Sounds like the each timers is executing in a independent thread? Now I am worry about the scenario of editing the same variable in different timeer, for example:


-- variable rooms is a global variable in the script

-- timer function is 
function OnTimer(newroom)
  local temp = rooms
  temp = rooms.."|"..newroom
  rooms = temp
end

if the OnTimer() function is invoked in different timer, will it lead me to some incorrect result? for example one of the newroom is not be added.

Nick Gammon said:

Twisol, in doc.cpp around line 4448, is the code that goes through timers:

I know MUSHClient is free. Is it open source? Where I can find the source code?

Nick Gammon said:

I haven't reproduced it yet.

Just try to create those two alias and timer in your game. Re-open and connect to game, type "CT". My MUSHClient is 4.51.

Twisol USA Mon 14 Jun 2010 11:25 PM #13

Wanghom8228 said:

Sounds like the each timers is executing in a independent thread? Now I am worry about the scenario of editing the same variable in different timeer, for example:


-- variable rooms is a global variable in the script

-- timer function is 
function OnTimer(newroom)
  local temp = rooms
  temp = rooms.."|"..newroom
  rooms = temp
end

if the OnTimer() function is invoked in different timer, will it lead me to some incorrect result? for example one of the newroom is not be added.

No, it's practically all single-threaded. The issue is that we could be running over the list of timers to fire the ones that need to go off, and one of those timers might modify the list we're going over. It's like you're on a set of train tracks, and suddenly a section of the track disappears. When the timer finishes and we continue checking the list, we could be in undefined territory. It depends on how the list is implemented internally. If it's an array, and the item that was removed (or added) is in an earlier part of the array, that's bad. If it's a linked list, it's perfectly fine as long as we didn't remove the one that we're on right now.

Wanghom8228 said:

Nick Gammon said:

Twisol, in doc.cpp around line 4448, is the code that goes through timers:

I know MUSHClient is free. Is it open source? Where I can find the source code?

At GitHub [1]. I have a fork I'm tinkering with too, but Nick's is the official one.

[1] http://github.com/nickgammon/mushclient

Twisol USA Mon 14 Jun 2010 11:28 PM #14

This page [1] implies says that map iterators should remain valid if the map changes underneath it, but I don't know if it applies to the MFC containers.

[1] http://www.sgi.com/tech/stl/Map.html

Wanghom8228 Tue 15 Jun 2010 12:07 AM #15

Thanks Twisol.
I feel much better to hear timers and triggers are all single-threaded. Otherwise I have many place need to update in my scripts. :)

I actually notice triggers have similar evaluation order issue.
For instance, we have a trigger (TriggerA)with keep-evalution=true and sequence=100. In the script of the trigger, we create another trigger (TriggerB) with sequence 90. Then the TriggerA will be triggered twice.

In my personal understanding, for keep-evaluted trigger, the better algorithm is go throught all the trigger together, but don't execute the corresponding script, and only keep the trigger point in a list. When all matched triggers are found, we execute the script one by one. But anyway, it is not a big deal to me. :)

Twisol USA Tue 15 Jun 2010 01:51 AM #16

Wanghom8228 said:
I actually notice triggers have similar evaluation order issue.
For instance, we have a trigger (TriggerA)with keep-evalution=true and sequence=100. In the script of the trigger, we create another trigger (TriggerB) with sequence 90. Then the TriggerA will be triggered twice.

That sounds odd. I've never run across that myself, though I admit I don't often create triggers dynamically.

Wanghom8228 said:
In my personal understanding, for keep-evaluted trigger, the better algorithm is go throught all the trigger together, but don't execute the corresponding script, and only keep the trigger point in a list. When all matched triggers are found, we execute the script one by one. But anyway, it is not a big deal to me. :)

Personally, I think that's a rather good point.

Twisol USA Tue 15 Jun 2010 02:05 AM #17

Huh, wow. Reproduced the above trigger issue, except it seems like it's gone into an infinite loop of some kind (and the program hangs). The trigger I used to test is below.

<triggers>
  <trigger
   enabled="y"
   keep_evaluating="y"
   match="foo"
   send_to="12"
   sequence="100"
  >
  <send>AddTriggerEx("", "foo", [[Note("Hi")]], 1, -1, 0, "", "", 12, 90)
Note("Trigger 1")</send>
  </trigger>
</triggers>

Tested with Simulate("foo\r\n").

When I attach to MUSHclient and pause it, it can't tell me where in the code it's paused at, which is annoying.

Twisol USA Tue 15 Jun 2010 02:19 AM #18

Reproduced again, minus the infinite loop.

<triggers>
  <trigger
   enabled="y"
   keep_evaluating="y"
   match="foo"
   send_to="12"
   sequence="100"
  >
  <send>if IsTrigger("testtrig") ~= 0 then
  AddTriggerEx("testtrig", "foo", [[Note("Hi")]], 1, -1, 0, "", "", 12, 90)
end
Note("Trigger 1")</send>
  </trigger>
</triggers>

Tested with: Simulate("foo\r\n")

Output:

foo
Trigger 1
Trigger 1

Something tells me the trigger list container uses an array offset as the position.

Nick Gammon Australia Forum Administrator Tue 15 Jun 2010 02:36 AM #19

Twisol said:

This page [1] implies says that map iterators should remain valid if the map changes underneath it, but I don't know if it applies to the MFC containers.

[1] http://www.sgi.com/tech/stl/Map.html

This definitely isn't STL here, so this isn't relevant, unfortunately.

In fact, as the MFC way of doing list and map iteration is to get the *next* pos while you are dealing with the current data (the data for the current pos) it is conceivable that if the current item invalidates the next item (which is the one pointed to by "pos") then it might indeed lead to a crash.

Twisol USA Tue 15 Jun 2010 02:38 AM #20

Nick Gammon said:
This definitely isn't STL here, so this isn't relevant, unfortunately.

Well, it's "relevant" - it's the same abstract structure, so it's not impossible for it to work the same way - but it's unlikely to be applicable.

Nick Gammon Australia Forum Administrator Wed 16 Jun 2010 02:34 AM #21

I can reproduce it with this:


require "addxml"
addxml.timer {  active_closed = true,
                second = 5,
                enabled = true,
                name = "timer1",
                send_to = sendto.script,
                send = [[

Note "In Timer1, Deleting timer2"
check (DeleteTimer "timer2")

]]
              }

addxml.timer {  active_closed = true,
                second = 5,
                enabled = true,
                name = "timer2",
                send_to = sendto.script,
                send = [[

Note "In Timer2, Deleting timer1"
check (DeleteTimer "timer1")

]]
              }

As I suspected, deleting an item in the list, one ahead of the one doing the deleting, invalidates the pointer (pos in the code) which should be pointing to the next item.

I have modified the timer handling to build a list of fired timers first, and then iterate through that list checking if the timer still exists. Thus, an item in the list, which an earlier timer deleted, won't be found, and the program won't crash.

Twisol USA Wed 16 Jun 2010 02:54 AM #22

It sounds like the same problem I found with triggers then, except I was adding and you were removing. Maybe the fix should be applied to triggers and aliases too.

Nick Gammon Australia Forum Administrator Wed 16 Jun 2010 03:58 AM #23

It is fiddlier in triggers - I looked.

A trigger that adds a trigger is kind-of a strange thing to do. I mean, it is like iterating through a table, from 1 to the end of the table, and for each item in the table, adding to it. This will create a loop, but is it really up to the table-handling code to detect this?

Twisol USA Wed 16 Jun 2010 04:20 AM #24

Nick Gammon said:

It is fiddlier in triggers - I looked.

A trigger that adds a trigger is kind-of a strange thing to do. I mean, it is like iterating through a table, from 1 to the end of the table, and for each item in the table, adding to it. This will create a loop, but is it really up to the table-handling code to detect this?

Not detect it, no, but I imagine it should be able to compile a list of the matching triggers and run over them, similar to the timers, no? If the original list is subject to change, it seems like a sensible thing to do in general.

Nick Gammon Australia Forum Administrator Wed 16 Jun 2010 04:52 AM #25

Look, I don't want to spend a lot of time fixing a problem that hasn't even been reported in the wild. Your example earlier on was contrived based on the problems with timers being deleted.

Triggers are harder because at the point of matching you also have the matching start and end columns, you also have the issue of "repeat on same line", and the fact that a matching trigger stops further triggers matching.

The "correct" behaviour hasn't even been defined, and we may not even get agreement about that. Is it ...

To disallow adding triggers from with a trigger firing?
To allow it but process only the existing triggers at that point? (ie. to defer the adding of the new trigger, or the deleting of an existing one)
To reconstruct the trigger list, and take into account any additions and deletions, even during the traversal of the list?

I have amended the documentation for AddTrigger and similar functions to warn against adding a trigger while a trigger is firing.

Twisol USA Wed 16 Jun 2010 08:51 AM #26

Nick Gammon said:
Look, I don't want to spend a lot of time fixing a problem that hasn't even been reported in the wild. Your example earlier on was contrived based on the problems with timers being deleted.

Okay.

I'm unsure about the timer fix, can you explain this to me? You have a list 'firedTimersList', you're adding to it, and you get the start position, but then you use that position in 'm_strMapList'...

CStringList firedTimersList; // created
// ...
  firedTimersList.AddTail (strTimerName); // adding
// ...
POSITION pos = firedTimersList.GetStartPosition(); // start
// ...
  strTimerName = m_strMapList.GetNext (pos); // ???

EDIT: Also, it complains that there is no GetStartPosition. There is a GetHeadPosition though.

Nick Gammon Australia Forum Administrator Wed 16 Jun 2010 09:41 AM #27

Very strange that it compiled, and even stranger that it ran OK.

Changed slightly now.

Copied and pasted a little too carelessly. ;)

Twisol USA Wed 16 Jun 2010 03:41 PM #28

The GetStartPosition thing was a silly copy/paste error on my part as well (since I changed it from a for to a whole in my code)). You can disregard that!