ColourNote bug

Posted by Rollanz on Fri 26 Apr 2019 07:09 PM — 11 posts, 40,804 views.

Rollanz Fri 26 Apr 2019 07:09 PM #0

I encountered some strange ColourNote() behaviour which sometimes (but not always) gives me a Run-time error. I have narrowed down the problem to interaction with a trigger.

The alias that is calling ColourNote:


<aliases>
  <alias
   name="targetting"
   match="^t (.+)$"
   enabled="y"
   regexp="y"
   send_to="12"
   keep_evaluating="y"
   sequence="100"
  >
  <send>require "tprint"
target="%1"
--print(target)

args={"red","blue", "Target changed to: ", "blue","red", target}
--tprint(args)

ColourNote("red","blue", "Target changed to: ", "blue","red", target)

if attacking==true then
  attack()
end</send>
  </alias>
</aliases>

When I use the alias, I sometimes get this error:


Run-time error
World: Achaea
Immediate execution
[string "Alias: targetting"]:8: bad argument #6 to 'ColourNote' (string expected, got no value)
stack traceback:
        [C]: in function 'ColourNote'
        [string "Alias: targetting"]:8: in main chunk

Further experimentation shows that the error only shows up the first time I use the alias after receiving a message (any message) from the server.

Further experiment showed that disabling a new trigger for capturing prompts, which I just introduced, prevents the message. The trigger is:


<triggers>
  <trigger
   enabled="y"
   group="prompt"
   keep_evaluating="y"
   match="^(.+)$"
   name="prompt"
   regexp="y"
   send_to="12"
   sequence="100"
  >
  <send>if GetLineCount() == GetInfo(289) then
  prompt_curr="%1"
end</send>
  </trigger>
</triggers>

Furthermore, the error does not happen if I call either print() or tprint() before the ColourNote in the alias (see commented out portions).

I suspect the issue is due to a race condition, but adjusting the sequence of the trigger up or down does not seem to resolve the issue.

Thanks in advance for your help.

Edit: I should add that I'm using Mushclient v5.06.

Nick Gammon Australia Forum Administrator Sat 27 Apr 2019 08:44 AM #1

Strange. Can you change the first line of your alias to read:


require ("tprint")

Then report what happens.

Rollanz Sat 27 Apr 2019 10:04 AM #2

Nick Gammon said:

Strange. Can you change the first line of your alias to read:


require ("tprint")

Then report what happens.

I have done so and it made no difference.

Nick Gammon Australia Forum Administrator Sun 28 Apr 2019 12:14 AM #3

There is more going on here than meets the eye. For one thing, scripts are always run to completion (unless you use coroutines) so race conditions should not apply. For another thing, if "target" was somehow nil, you would get a different error. For example:


require "tprint"
target="%1"

target = nil

ColourNote("red","blue", "Target changed to: ", "blue","red", target)

if attacking==true then
  attack()
end

Gives the error:


Run-time error
World: smaug2
Immediate execution
[string "Alias: targetting"]:6: bad argument #6 to ColourNote' (string expected, got nil)
stack traceback:
        [C]: in function 'ColourNote'
        [string "Alias: targetting"]:6: in main chunk

Notice the different error message. Have you replaced the Lua DLL with something else, like LuaJIT?

Nick Gammon Australia Forum Administrator Sun 28 Apr 2019 12:16 AM #4

The only way the error reads "got no value" is if you omit the argument altogether, like this:


ColourNote("red","blue", "Target changed to: ", "blue","red")

Rollanz Sun 28 Apr 2019 03:07 AM #5

Nick Gammon said:

There is more going on here than meets the eye. For one thing, scripts are always run to completion (unless you use coroutines) so race conditions should not apply. For another thing, if "target" was somehow nil, you would get a different error. For example:


require "tprint"
target="%1"

target = nil

ColourNote("red","blue", "Target changed to: ", "blue","red", target)

if attacking==true then
  attack()
end

Gives the error:


Run-time error
World: smaug2
Immediate execution
[string "Alias: targetting"]:6: bad argument #6 to ColourNote' (string expected, got nil)
stack traceback:
        [C]: in function 'ColourNote'
        [string "Alias: targetting"]:6: in main chunk

Notice the different error message. Have you replaced the Lua DLL with something else, like LuaJIT?

I have not made changes to any Lua DLLs since I installed MushClient. The printout on world load says it's using Lua 5.1.4. I do have a paths variable pointing to Lua 5.3.5, if that's relevant.

Additional troubleshooting steps I've taken since the last post:
-uninstalling all plugins did not resolve the issue
-reinstalling MushClient did not resolve the issue
-the issue continued when I created a new world with only the trigger and alias
-commenting out all of the code in the trigger did not resolve the issue

I hadn't paid attention to this before, but the first part of the colour note ("Target changed to: ") printed fine in red on blue.

Nick Gammon Australia Forum Administrator Sun 28 Apr 2019 06:11 AM #6

The good news is I can reproduce this. Also I think you are right about the race condition. So far what I have is:

You have a prompt line which is not terminated by a newline
Your trigger matches any text (therefore it matches the prompt)
Your alias does a ColourNote which outputs to the output window
When it attempts to do so it notices that there is an unfinished line from the MUD, being the prompt
It terminates the line from the MUD, which then causes triggers to be evaluated, including the prompt trigger
Since the trigger is “send to script” it calls the Lua script engine (you can comment out what the script does, and the same thing happens - as you noted)
Calling the script engine, in the middle of evaluating the call to ColourNote somehow corrupts the internal Lua state - this is the race condition. Probably because the first 3 arguments to ColourNote triggers the problem, and the problem is noticed when you process the next 3 arguments.

As you have noted, a workaround is to print something, anything (including just a blank line). That terminates the previous prompt line from the MUD and causes the trigger to be evaluated, but not in the middle of doing a ColourNote. Another thing you could possibly do is make the MUD terminate its prompts with a newline.

However I agree it is a bug, but I’m not sure how to totally stop this, since it rears its head while already doing a ColourNote. Probably forcing the checking for a previous unterminated line earlier would help.

Nick Gammon Australia Forum Administrator Sun 28 Apr 2019 06:26 AM #7

Interestingly, I think this bug must have been around for a while. Congratulations on finding it! I think possibly a fix in version 4.99 might have contributed:

http://www.gammon.com.au/scripts/showrelnote.php?version=4.99&productid=0

Nick Gammon Australia Forum Administrator Sun 28 Apr 2019 08:58 PM #8

I believe I have fixed that in version 5.07 (pre-release) which you can download following the instructions here:

http://www.gammon.com.au/forum/?id=13903

Fix details:

https://github.com/nickgammon/mushclient/commit/4d5115b192da90ef4

Death Fri 10 May 2019 11:55 AM #9

I noticed a problem in this as well, and ended up having to use other means to do what I wanted to do. I'm glad its getting fixed!

On another note: I've experienced a weird issue of a similar note:

When using control+I, I can simulate a colourtell that works perfectly, but when I put the actual code into my plugins, they don't work.

I found out I needed to separate the one large colourtell into many more smaller colourtells instead of one big one.

Is this supposed to be how it works?
Why would it work in the Control+I IMMEDIATE window, but not in code in my plugin?

Let me know if you need an example.

Nick Gammon Australia Forum Administrator Fri 10 May 2019 08:22 PM #10

I would need to see the code to comment. It should work.

when I put the actual code into my plugins, they don’t work

You also need to define what you mean by “don’t work”. You see nothing? It is the wrong colour? The wrong place? Some appears but not all?