Notice: Any messages purporting to come from this site telling you that your password has expired, or that you need to verify your details, confirm your email, resolve issues, making threats, or asking for money, are
spam. We do not email users with any such messages. If you have lost your password you can obtain a new one by using the
password reset link.
Due to spam on this forum, all posts now need moderator approval.
Entire forum
➜ MUSHclient
➜ Bug reports
➜ Full lines received within a packet, Note(), and triggers
Full lines received within a packet, Note(), and triggers
|
It is now over 60 days since the last post. This thread is closed.
Refresh page
Pages: 1
2 3
4
5
Posted by
| Nick Gammon
Australia (23,140 posts) Bio
Forum Administrator |
Date
| Reply #15 on Tue 30 Jun 2015 08:47 PM (UTC) |
Message
| I'm not sure this can be easily fixed (apart from the suggested change of delaying the note for a short time).
Lines in the output window are one of three types: MUD output / Note / User input.
These types are established at the start of the line, and then the line gets added to until a newline, or a line type change. So, for example, doing a note finishes the current MUD output line (if any) and switches to "note type".
There also appears to be quite a bit of code that makes sure that the line type is preserved over line breaks, so for example, if a note spans two lines, the second line is still a note.
What your Note in the GMCP callback has done is finished the "MUD output" line and switched it to a Note line. Then when the rest of the text is processed it is still a Note line. Note lines are not evaluated for triggers.
I think the simplest solution is to use the DoAfterSpecial call, to delay outputting the note. We can regard it as a (design) limitation that you don't attempt to do displays during telnet subnegotiation sequences. |
- Nick Gammon
www.gammon.com.au, www.mushclient.com | Top |
|
Posted by
| Galaban
(19 posts) Bio
|
Date
| Reply #16 on Tue 30 Jun 2015 09:00 PM (UTC) |
Message
| I'm almost certainly wrong, but it looks like CMUSHclientDoc::StartNewLine is setting the ->flags for the current line to the value that is being passed in.
Right around here (line 2556):
m_pCurrentLine = new CLine (++m_total_lines,
m_nWrapColumn,
iFlags, // style flags
iForeColour,
iBackColour,
m_bUTF_8);
m_pCurrentLine->flags = flags;
pos = m_LineList.AddTail (m_pCurrentLine);
What's happening is that the Note() is sending 1 into the StartNewLine() function, indicating that the current line is a Note. However, this code above is interpreting it as the next line is a Note.
We return from that function, maintaining that m_pCurrentLine pointer for the next round of text that comes in. That's causing it to get flagged as a note.
I don't know why it works for regular note-before-mud-input-text combos, but I'm sure there's some reason.
Maybe that will help out...
Thanks,
Galaban | Top |
|
Posted by
| Galaban
(19 posts) Bio
|
Date
| Reply #17 on Tue 30 Jun 2015 09:01 PM (UTC) |
Message
| Aah, that makes sense for multi-line notes... Hmm.
This is definitely a tricky bug. | Top |
|
Posted by
| Nick Gammon
Australia (23,140 posts) Bio
Forum Administrator |
Date
| Reply #18 on Tue 30 Jun 2015 11:41 PM (UTC) |
Message
| I'm not really defending the code, but the way I recall doing it, there always had to be a current line (otherwise m_pCurrentLine would be NULL at the very start of a new world).
Thus, there was a current line before we were sure what sort of line it would be. And the decision to make the current line a certain type would happen at the start of that line. Not when the line was created, but when we start putting stuff into it.
So, for example, for a Note, it first checks if we have a current Note line, in which case the Note is appended to it.
But for MUD output, if the line is not already MUD output, then it terminates it, and starts a new line, and marks it MUD output.
Now, in the case in question, we have MUD output, so the line is started as a MUD output line. And indeed it is MUD output. However it then process the GMCP stuff which (perhaps to the surprise of the function) now terminates that line and converts it to a Note line. But now when we get the "real" output we have passed the decision point for setting the line type, so it stays a Note line. |
- Nick Gammon
www.gammon.com.au, www.mushclient.com | Top |
|
Posted by
| Manacle
(28 posts) Bio
|
Date
| Reply #19 on Wed 01 Jul 2015 12:25 AM (UTC) Amended on Wed 01 Jul 2015 12:35 AM (UTC) by Manacle
|
Message
| In fact, it doesn't really seem to be a bug. It seems that the code as it is is taking reasonable measures and giving a fairly consistent, if surprising, reaction to exceptional circumstances.
The issue we're having is that we're jumping the gun in processing some control information. If we know that there may be additional information in the line, perhaps the easiest way to handle this is to just alter the GMCP plugin we're using to allow that line to be processed completely before it broadcasts information about the updated GMCP table.
Is there a way to elegantly add a delay until the current line is done processing (does that sentence even make sense in the context of how MushClient processes lines?) Because I think the way this is being handled by the client makes sense and is reasonably consistent, I prefer to frame this issue as a (very subtle) bug in the current GMCP plugin. I really don't want to have to remember to do this: (Delay("Note ...")) every time I respond to a GMCP broadcast.
What I'd really like to do is to do this to this line:
BroadcastPlugin(1,message)
to
DoAfterSpecial(.1,BroadcastPlugin(1,message))
but of course I'd rather do this immediately rather than after a 10th of a second (it's quite possible to receive several GMCP messages in that timeframe). | Top |
|
Posted by
| Nick Gammon
Australia (23,140 posts) Bio
Forum Administrator |
Date
| Reply #20 on Wed 01 Jul 2015 01:32 AM (UTC) |
Message
| Not a direct answer but see "How MUSHclient processes text arriving from the MUD":
http://www.gammon.com.au/forum/?id=6554
Quote:
Is there a way to elegantly add a delay until the current line is done processing ...
The plugin callback OnPluginLineReceived might do that for you. I think at that point the line would be assembled but the triggers not yet processed. You could try that. Have the plugin push various GMCP messages into a queue, and empty that queue when OnPluginLineReceived is called. |
- Nick Gammon
www.gammon.com.au, www.mushclient.com | Top |
|
Posted by
| Manacle
(28 posts) Bio
|
Date
| Reply #21 on Wed 01 Jul 2015 03:18 AM (UTC) |
Message
| Sadly, this ends up in the same position that the trigger fix posted above finds itself. It works fine if this issue DOES crop up, but if GMCP is received on its own, the queue isn't emptied until the next actual line is processed. | Top |
|
Posted by
| Manacle
(28 posts) Bio
|
Date
| Reply #22 on Wed 01 Jul 2015 05:19 AM (UTC) |
Message
| If I wanted to add in some hack that at least attempted to deal with this, is it possible that this might work in many cases? I can see in doc.cpp that received lines are handled by a state machine with no character memory, so...
Can I assume that at least (most of the time, after any initial negotiations are done) that I'm not THAT likely to have many telnet subnegotiation codes on the same line?
If so, then can I assume that if I see the character sequence (note that \c9 is the code for GMCP) below start on a packet received from the MUD:
\ff\fa\c9(.+)\ff\f0, where .+ doesn't include the sequence \ff\f0 itself unless there are an even number of \ff characters
followed by a character that is not an IAC (\ff - UNLESS this IAC character is escaped by itself) that, for the most part, I'm seeing a GMCP message followed by an output line in the same packet?
I'm assuming that if I see an ESC (\1b) after subnegotiation that this will end up being an ANSI code and I should at least hope that I'll have a line after it, or should I also check for the ';' character and make sure I have non-IAB data afterward (ie, is it common for the MUD to send ANSI information without actual output data afterward?)
My plan is to use OnPluginPacketReceived (I assume I'll have to think about what happens if I encounter a partial packet) to examine the incoming packets to check for this situation. If I can make the assumptions I listed above, it shouldn't be too difficult to catch most instances of this failure. I don't intend to change the packet information, but I intend to enable queueing behavior in the GMCP plugin we're using when I detect this situation (otherwise, I'll have it behave normally). Assuming my above assumptions are (more or less) true, this should fix most instances of this unexpected behavior while having its very worst failure case result in a delay in broadcasting some GMCP data until one additional line comes in from the MUD.
Am I missing some intricacy in the communication between the game and the client that might trip me up? | Top |
|
Posted by
| Nick Gammon
Australia (23,140 posts) Bio
Forum Administrator |
Date
| Reply #23 on Wed 01 Jul 2015 05:38 AM (UTC) |
Message
| I'm not sure what all that complexity gets you. Probably most of the GMCP messages would be followed fairly promptly by other ones. MUDs are generally not quiet places. What would be the problem with just the DoAfterSpecial with a short delay? You will see the tick message within a 10th of a second or so.
I'm going to regard this as a documentation problem, and amend the documentation for the OnPluginTelnetSubnegotiation callback to warn you to not do notes. I notice, interestingly, that the GMCP debug mode seems to do just that (does a note) so if there were major problems wouldn't this have cropped up already? Or maybe not many people turn the debugging mode on.
There are other ways you can probably screw around with the way the client handles data, for example doing a Simulate to put more data into the incoming stream, in places it isn't expected.
If I was rewriting the client today, there are quite a few things I would do differently, based on experience, but I'm reluctant to touch things like that, because of all the comments, and commented-out code, that indicates that doing it this way is actually solving other problems. |
- Nick Gammon
www.gammon.com.au, www.mushclient.com | Top |
|
Posted by
| Galaban
(19 posts) Bio
|
Date
| Reply #24 on Wed 01 Jul 2015 09:32 AM (UTC) Amended on Wed 01 Jul 2015 10:24 AM (UTC) by Galaban
|
Message
| Regarding the Workaround
My first workaround was a DoAfterSpecial call. However. I found that this was... really quite aweful.
What happened was that we would get a -->TICK<-- message (part of that very packet we're trying to process) and then we would process it several lines later. It looked like the plugin was simply unresponsive or that it wasn't tied to the tick message. This may seem alright, but it just looked unprofessional.
That's why I did the temporary, one-shot trigger. Yes, it delays it one line. However, that one line always comes in the same packet.
Even if we get a line of GMCP data "on it's own", we get a new line with it. That's how Aardwolf was coded.
Now, again, this hacky workaround will cause multi-line triggers to fail. It has great potential to mess things up. However, it is better than delaying the output by 0.1 seconds (which is almost always several lines of mud output). | Top |
|
Posted by
| Galaban
(19 posts) Bio
|
Date
| Reply #25 on Wed 01 Jul 2015 09:41 AM (UTC) Amended on Wed 01 Jul 2015 10:24 AM (UTC) by Galaban
|
Message
| Regarding the "bug" discussion
Manacle said:
In fact, it doesn't really seem to be a bug. It seems that the code as it is is taking reasonable measures and giving a fairly consistent, if surprising, reaction to exceptional circumstances.
I disagree.
I see this as an architectural bug. Note text should be counted as Note text and mud text as mud text. Remember, what we're talking about here is that if I fire a Note() on a TelnetSubnegotiation, the next trigger will fail to fire.
At what point can I reasonably expect a trigger to not fire?
Don't get me wrong. I've looked at the code and I understand how it was designed and the assumptions that were made. But just because the assumptions make sense does not mean that the results are accurate. I believe that this can and should be fixed.
This is a bug. Triggers are not firing.
What other situation causes this? Does this happen when we echo the input? What about when we turn on tracing? Will all triggers stop firing if I use "gmcpdebug 1"? All of these are using the DisplayMsg function and altering the flags of the next line.
If this won't be fixed, triggers in Mushclient will be viewed as unreliable. Just listen to how it sounds: "If you use a Note(), Tell() or AnsiNote(), it might cause the next line of mud input to be ignored by triggers". Doesn't sound too good.
Look, I already have my workaround and it's solid. I just believe that this bug is much bigger than my little "moons" plugin. And I believe it needs fixed. | Top |
|
Posted by
| Galaban
(19 posts) Bio
|
Date
| Reply #26 on Wed 01 Jul 2015 10:21 AM (UTC) Amended on Wed 01 Jul 2015 10:25 AM (UTC) by Galaban
|
Message
| The fix:
unsigned char save_flags = m_pCurrentLine->flags;
DisplayMsg (strFullMsg, strFullMsg.GetLength (), COMMENT);
// Reset the next output line to make sure that our comment above doesn't cause
// any mud input to be treated as a comment.
m_pCurrentLine->flags = save_flags;
This would only need to be done in CMUSHclientDoc::Tell and CMUSHclientDoc::Trace . However, it might be worth evaluating other places where we force a COMMENT, such as CMUSHclientDoc::CheckTimerList :
if (!strExtraOutput.IsEmpty ())
DisplayMsg (strExtraOutput, strExtraOutput.GetLength (), COMMENT);
I tested it and it solved the problem. | Top |
|
Posted by
| Nick Gammon
Australia (23,140 posts) Bio
Forum Administrator |
Date
| Reply #27 on Wed 01 Jul 2015 09:02 PM (UTC) |
Message
|
Galaban said:
Ooh, that's nice output. How do we get that line info?
Select something on the line, then go to Display -> Text Attributes -> Line Info.
Quote:
I tested it and it solved the problem.
Not quite. It solved that particular problem with that exact test setup. The problem that I have is to make sure it doesn't introduce other problems, which it does. After applying the suggested changes, I thought to myself "what if you do a Tell which doesn't terminate the line?".
What happens with your change is that we are halfway through the line, and you are supposed to be able to do multiple Tells which each add to the current line. Now by switching the line type back to MUD output, each one thinks it has to terminate the MUD output, and start Note output.
So if we change your plugin to do this:
if (text == "comm.tick {}") then
Tell ("---")
Tell ("GMCP TICK")
Note ("---")
end
The output window now reads:
---
GMCP TICK
---
You see the grey moon rising in the east.
---------------
--> TICK <--
Not acceptable. We have disabled the Tell functionality and degraded it to Note behaviour. |
- Nick Gammon
www.gammon.com.au, www.mushclient.com | Top |
|
Posted by
| Manacle
(28 posts) Bio
|
Date
| Reply #28 on Wed 01 Jul 2015 09:02 PM (UTC) Amended on Wed 01 Jul 2015 09:06 PM (UTC) by Manacle
|
Message
| Galaban, I wasn't saying that I didn't think not firing a trigger on a line that we expected it to fire on wasn't a bug. I suppose a cleaner way of saying what I meant was that I think the bug was that the GMCP plugin we're using fires Note() calls in the middle of OnPluginTelnetSubnegotiation(). Yes, it was because of behavior that wasn't understood and (understandably) not documented. I just don't have a problem with the fact that in this very unusual circumstance that MushClient produced unexpected and undesirable results.
For the nonce, without requiring update to the hardcode, this change in the GMCP plugin also solves the problem with a minimum of behavioral change:
Replace the OnPluginTelnetSubnegotiation function with
GMCPMessageQueue = {}
function OnPluginTelnetSubnegotiation (msg_type, data)
if msg_type ~= GMCP then
return
end -- if not GMCP
if GMCPDebug > 0 then ColourNote ("darkorange", "", data) end
message, params = string.match (data, "([%a.]+)%s+(.*)")
if not message then
return
end -- if
if not string.match (params, "^[%[{]") then
params = "[" .. params .. "]" -- JSON hack, make msg first element of an array.
end -- if
local succ,t = pcall(json.decode,params)
if succ and type(t) == "table" then
gmcpdata = gmcpdata or {}
-- Create the higher level tables based on tag such as char.vitals or room.info etc.
-- Lowest level of those will be the 'parent' for parse_gmcp
local parent = gmcpdata
for item in string.gmatch(message,"%a+") do
-- reset data hacks
if (item == "room" and message:sub(1,13) ~= "room.wrongdir") -- don't let room.wrongdir erase current room info
or item == "comm" or item == "group" then
parent[item] = nil
end
parent[item] = parent[item] or {}
parent = parent[item]
end
parse_gmcp(t,nil,parent)
--This if/print will result in bad behavior
--for GMCP packets with embedded output lines
if GMCPDebug > 1 then
print ("gmcpdata serialized: " .. serialize.save_simple(gmcpdata))
end
--BroadcastPlugin(1,message)
--Doing it this way to avoid interrupting a line that contains both
--GMCP data and normal data. We want to process the GMCP *after* we've
--generated the full "normal" line from the MUD. See
--OnPluginLineReceived(), OnPluginTick()
table.insert(GMCPMessageQueue, message)
-- Examples of use from here on. Can be uncommented for debug.
--print("Testing room.info.exits table : " .. gmcpval("room.info.exits")) -- serialized table.
--print("Testing correct room name : " .. gmcpval("room.info.brief")) -- single field
--print("Testing character str stat : " .. gmcpval("char.stats.str")) -- single number.
--print("Testing top-level value : " .. gmcpval("char")) -- all char table.
--print("Testing bad top-level value : " .. gmcpval("sdlkfsldf")) -- nil (not error)
--print("Testing bad lower level : " .. gmcpval("blah.1.2.3")) -- nil
--print("Testing bad lower level inside good: " .. gmcpval("room.info.hinick")) -- nil
--print("Testing north exit, deeper nest : " .. gmcpval("room.info.exits.n"))
-- End of test cases.
else
ColourNote("white","red","GMCP DATA ERROR: "..t)
end -- if
end -- function OnPluginTelnetSubnegotiation
function OnPluginLineReceived()
--Capture here to do our best to broadcast GMCP
--BEFORE triggers are run on embedded lines
OnPluginTick()
end
function OnPluginTick()
--Capture here to broadcast GMCP shortly after
--any GMCP line, even if no output text is
--embedded.
if #GMCPMessageQueue > 0 then
for i=1, #GMCPMessageQueue do
BroadcastPlugin(1, GMCPMessageQueue[i])
end
GMCPMessageQueue = {}
end
end
(Still prefer Galaban's C solution, but for the moment...)
This works for the moment, and it seems to avoid certain unexpected behavior that I was running into before. The situation is, particularly for moon plugins, that we need the GMCP Broadcast to happen BEFORE triggers happen on the embedded line. Otherwise, with moon plugins in particular and, more general, for all plugins that track ticks, there will be one line of input that technically came after the tick but will be matched for triggers before that tick is broadcast to other plugins. Obviously, with moon plugins, this minor discrepancy has a fairly large effect. It is for this reason that I capture both OnPluginTick() AND OnPluginLineReceived(), because OnPluginLineReceived fires before triggers are evaluated. I capture on OnPluginTuck() because I experienced behavior contrary to Galaban's; sometimes OnPluginLineReceived() alone fires too late for my tastes and was delaying GMCP broadcasts until an ADDITIONAL line was received from the MUD.
I do not know if I will run into concurrency issues. | Top |
|
Posted by
| Nick Gammon
Australia (23,140 posts) Bio
Forum Administrator |
Date
| Reply #29 on Wed 01 Jul 2015 09:13 PM (UTC) |
Message
| Isn't the ---TICK--- line just debugging? You can do other stuff, just don't display things immediately. |
- Nick Gammon
www.gammon.com.au, www.mushclient.com | Top |
|
The dates and times for posts above are shown in Universal Co-ordinated Time (UTC).
To show them in your local time you can join the forum, and then set the 'time correction' field in your profile to the number of hours difference between your location and UTC time.
152,218 views.
This is page 2, subject is 5 pages long:
1
2 3
4
5
It is now over 60 days since the last post. This thread is closed.
Refresh page
top