Register forum user name Search FAQ

Gammon Forum

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

Manacle (28 posts) Bio

Date

Reply #30 on Wed 01 Jul 2015 09:33 PM (UTC)

Message

I do a lot of things on tick.

I output moon status in some circumstances (ie, I output every tick during the 3 moons. I also output an additional moon messages, "The black moon has fallen completely." because the game actually outputs its falling message the tick before the moon is gone).

There are circumstances in which I have other messaging running on ticks (when I have brewed/scribed items that are going to dissolve, for instance, and in certain times I've found it useful to have a tick counter that outputs a short message every 10-30 ticks.)

For me, it's that this behavior is completely unexpected, affects a plugin that I'd like to be able to trust completely, and when unexpected results happen, they're not consistent and if I'm not careful could be almost impossible to resolve in the future unless I always keep this counter intuitive behavior on my mind.

It's also worth noting that it's easy for a plugin completely unrelated to any of mine that I may be using or testing to cause this issue without intention. That's why I'm not eager to have a solution that requires thought upon any plugins actually using GMCP but instead am looking for a solution that fixes the problem more centrally. For instance, my moons plugin was interrupting Fiendish's chat plugin every so often and causing it to miss messages.

The most damning thing is that this behavior allows plugins to inadvertently and deleteriously affect other plugins silently. A lot of work has gone into making that very difficult to do, but all this takes is one callback and one function in that callback, and ironically it's the very same function that is used most often to attempt to debug these very types of issues.

It's sort of the GMCP plugin's fault for not advertising that you shouldn't use Note() calls when responding to any information it broadcasts, but... No, that's a bit much. At least in Aardwolf... What am I supposed to do, add a timer delay to everything I do in response to GMCP if it might lead to a Note()? There's no way I can expect every single plugin that ANY of my users might run to do that, but I do have to expect that in the case of a Moons plugin, because those messages are tied firmly to the Tick() GMCP poke. This is why I'm trying so hard for a central solution.

Posted by

Manacle (28 posts) Bio

Date

Reply #31 on Wed 01 Jul 2015 10:51 PM (UTC)

Message

Neat. Another instance of this cropping up is a plugin I use to append GMCP room numbers to the end of room names. For a long time, during runs, it would only output the number every second room, but it seems that this was the root of that issue to. That's also a situation, given that room movement happens every 1/8second, that it would be very easy for an insufficiently granular timer to cause more unexpected behavior.

Posted by Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date Reply #32 on Thu 02 Jul 2015 04:15 AM (UTC)

Message

There may be a way of fixing it, but the proposed code in reply #26 wasn't it, for reasons I explained.

One idea that springs to mind is the m_OutstandingLines list. This is currently used to save up Tells and Notes that are done before the output window exists.

Conceivably that could be leveraged to do something similar if we know we are processing some out-of-band data, like telnet data. So, if a certain flag is set, the notes are batched, and then output afterwards.

There are more subtle problems than just switching the line type when a GMCP message arrives. Imaging this for example:


You have {GMCP subnegotiation here} died.

Now if we just output notes in the GMCP subnegotiation by terminating the current line, starting a note line, and then re-starting a MUD line we will get:


You have 
{GMCP subnegotiation here}
 died.

So, a trigger on "You have died." will fail.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Galaban (19 posts) Bio

Date

Reply #33 on Thu 02 Jul 2015 10:05 AM (UTC)

Message

Nick Gammon said:

There may be a way of fixing it, but the proposed code in reply #26 wasn't it, for reasons I explained.

OK, fair enough. Honestly, my goal wasn't to propose a final solution. I knew that it was probably insufficient. I was simply trying to make sure that this thread didn't die and that this bug didn't get fixed. I was trying to float an idea out there that would help keep things alive.

To me it felt like the previous posts were indicating that this wasn't going to get fixed.

Manacle said:

The most damning thing is that this behavior allows plugins to inadvertently and deleteriously affect other plugins silently.

I completely agree and this is why I don't see this as a bug on the plugins part, but as a bug in the Mushclient code. Until I actually dove into the Mushclient code, it made no sense that a Note() should cause the next line of text to fail to fire a trigger.

I apologize if I stepped on anyone's toes. It simply seemed like this was bug was being written off as "too hard" or "as designed", when it's definitely neither. While it may be hard, the payoff is significant. While it may be how it was originally designed, this behavior is broken.

Thank you for continuing to investigate this and work towards a solution.

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #34 on Thu 02 Jul 2015 09:02 PM (UTC)

Message

I just want to point out that you can't necessarily do everything you might want to, in a script. For example, a plugin can't delete itself.

However in this particular case I think I have a compromise. I have tested the idea of deferring notes until the end of the current line. This seems to be working (even with the extra Tells I had in my recent post).

So basically the callback is called at the same time it always was, and can do whatever it wants - within reason. However attempts to output to the current line are pushed into a queue, and saved until "end of line" processing - which should happen when the newline for the line you are trying to trigger on arrives.

The only "gotcha" here would be if you got the tick but no newline. Do you think this is likely to happen? We can probably also empty the outstanding notes buffer on timer processing which happens every 1/10 of a second. I think that usually happens between lines, although it is possible, I think, that you might get a partial line, and then the timer kicks in, and then another partial line.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #35 on Thu 02 Jul 2015 09:03 PM (UTC)

Message

To make the solution more general, I have applied it to all places where plugin callbacks are called. This includes things like MXP tags and so on. These are probably also places where you don't want notes in the middle of a line.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #36 on Thu 02 Jul 2015 11:17 PM (UTC)

Message

See: http://github.com/nickgammon/mushclient/commit/9151f01

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Galaban (19 posts) Bio

Date

Reply #37 on Mon 06 Jul 2015 09:30 AM (UTC)

Message

Nick Gammon said:

The only "gotcha" here would be if you got the tick but no newline. Do you think this is likely to happen?

This would cause all sorts of problems. I see it as unlikely. I doubt that the "\n" at the end of the gmcp data is conditional. Even in muds that have telnet subnegotiation mid-line, I see it as most likely hard-coded to not be hard-coded. New lines are something I think we can rely on. I would imagine that Muds/mushs that don't send them would have other trigger issues.

Thanks for the fix!

Posted by

Fiendish USA (2,535 posts) Bio Global Moderator

Date

Reply #38 on Thu 25 Feb 2016 12:27 AM (UTC)

Amended on Thu 25 Feb 2016 01:06 AM (UTC) by Fiendish

Message

I'm revisiting this thread, because I've been experiencing funny undesired behavior in MUSHclient for a while, and have suddenly realized that the change made because of this thread is the cause of my problems.

I've also found that the behavior being discouraged here, printing data to the screen during subnegotiation callbacks, is extremely useful. IMO, it's not good to require messages from the server before satisfying requests from the user. The result is that I right now offscreen have literally dozens of hidden-from-me messages piling up in this print queue not getting shown until I type "look" or "score" or something entirely unrelated, at which point my piled up prints don't just display but they get interleaved after the first line of the resulting output from the entirely unrelated command.

Unless, that is, I...

Just replace all of my print statements with DoAfterSpecial(0.1, etc. as suggested in the middle of the thread?

Which I am absolutely going to do, because that at least appears to solve my problem. So where does that leave any of this? The committed fix has broken something useful (printing gmcp), but won't this workaround just re-break the original complaint? What's the real difference between a note from subnegotiation and an arbitrarily short delayed note from subnegotiation that makes one of them bad and one good?

And I'm left wondering, couldn't MUSHclient just take all my prints and Notes that it is now refusing to show and just automatically convert them to DoAfterSpecial(0.1 for me? At least then code that used to work would continue to work.

Quote:
You have {GMCP subnegotiation here} died.

I think that this is a bonkers example that should be considered a giant server bug and should not be fixed in the client at the expense of other useful operation. I cannot believe that a properly functioning server will send only half of a message, stop what it's doing mid-sentence, send a different message, and then resume sending the rest of the first message. I just can't imagine any server working that way.

Quote:
I'm not sure what all that complexity gets you. Probably most of the GMCP messages would be followed fairly promptly by other ones.

I consider this an invalid assumption because I'm running into the problem right now trying to do something for Aardwolf. :\

Quote:
MUDs are generally not quiet places.

Actually, I think exactly the opposite. MUDs tend to be very quiet places if you disable the needless spam.

Quote:
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.

Yes, I noticed this too. I'm reporting it now as something that has bothered me since 4.99. :\

https://github.com/fiendish/aardwolfclientpackage

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #39 on Thu 25 Feb 2016 06:08 AM (UTC)

Amended on Thu 25 Feb 2016 06:09 AM (UTC) by Nick Gammon

Message

This reminds me of quite a few threads on the Arduino Forum. There are things called ISRs (Interrupt Service Routines) which can happen asynchronously, or in other words, when you don't expect them.

Now ISRs can be tricky to debug, so people put debugging prints inside them. Unfortunately that generally makes things worse:

The processor may lock up entirely because the serial prints can't be serviced with interrupts off
The fact of printing alters the timing of the ISR

So I say: "Don't do serial prints inside an ISR". And the user replies "But I want to! It's helpful!".

Quote:

... printing data to the screen during subnegotiation callbacks, is extremely useful ...

No doubt. But you have to design it differently. You could do a table.insert of your message, and have a timer pull them out every 10th of a second, for example.

Quote:

Just replace all of my print statements with DoAfterSpecial(0.1, etc. as suggested in the middle of the thread?

Which is effectively the same thing.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Fiendish USA (2,535 posts) Bio Global Moderator

Date

Reply #40 on Thu 25 Feb 2016 08:46 AM (UTC)

Amended on Thu 25 Feb 2016 05:40 PM (UTC) by Fiendish

Message

The major problem is that this comment here is exactly spot on:

Quote:
What am I supposed to do, add a timer delay to everything I do in response to GMCP if it might lead to a Note()? There's no way I can expect every single plugin that ANY of my users might run to do that

And this later dismissal of concern is not valid, and is based on, I think, the player misunderstanding your question.:

Galaban said:

Nick Gammon said:

The only "gotcha" here would be if you got the tick but no newline. Do you think this is likely to happen?

This would cause all sorts of problems. I see it as unlikely.

It's in fact quite easy to get GMCP without a following in-band message. (Especially now that Aardwolf has added GMCP-only channels, which makes the data easier to manage. Honestly, I'd be happy with everything coming from the server silently out of band with JSON structure and then scripts choosing which parts to show where, but that's maybe a dream for a distant future.)

So should all subnegotiation handlers be themselves DoAfterSpecialing their broadcasts or something? That's the only viable alternative I can think of, though it will mean a lot of script changes across the board if this isn't done automatically under the hood because the canonical demonstration of handling GMCP broadcasts relies on checking the sender plugin ID.

Nick Gammon said:

Quote:

... printing data to the screen during subnegotiation callbacks, is extremely useful ...

No doubt. But you have to design it differently. You could do a table.insert of your message, and have a timer pull them out every 10th of a second, for example.

Quote:

Just replace all of my print statements with DoAfterSpecial(0.1, etc. as suggested in the middle of the thread?

Which is effectively the same thing.

My question is though...
If putting a Note on the screen at a moment in time that is arbitrarily unrelated to the receipt of in-band messages breaks the handling of a subsequent in-band message, wouldn't the exact same thing happen when putting a Note on the screen at a slightly different arbitrarily unrelated moment in time?

If the answer is "No, of course not. You obviously didn't read the thread closely enough." then I think a more good change is to have one of the following:

1) notes sent from inside subnegotiations get automatically converted "DoAfterSpecial(0.1,..." for the noting and therefore continue working as written instead of requiring different syntax. (Maybe not all callbacks though! A non-subnegotiated trigger should be able to broadcast without conflict!)

or

2) broadcasts sent from inside subnegotiations get automatically converted to use "DoAfterSpecial(0.1,..." for the broadcasting, which of course then also requires forwarding the proper ID.

https://github.com/fiendish/aardwolfclientpackage

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #41 on Thu 25 Feb 2016 09:51 PM (UTC)

Message

Yes, but, sending something after 0.1 seconds or some other interval can result in an note line appearing in the middle of an input or output line.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Fiendish USA (2,535 posts) Bio Global Moderator

Date

Reply #42 on Fri 26 Feb 2016 08:02 PM (UTC)

Message

Nick Gammon said:

Yes, but, sending something after 0.1 seconds or some other interval can result in an note line appearing in the middle of an input or output line.

"Yes, but" to which statement?
Is this a "four legs good, two legs bad" or a "four legs bad, two legs also bad" situation?

https://github.com/fiendish/aardwolfclientpackage

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #43 on Fri 26 Feb 2016 08:27 PM (UTC)

Message

Fiendish said:

"Yes, but" to which statement?

This one:

Quote:

... notes sent from inside subnegotiations get automatically converted "DoAfterSpecial(0.1,..." for the noting ...

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Posted by

Fiendish USA (2,535 posts) Bio Global Moderator

Date

Reply #44 on Sat 27 Feb 2016 12:07 PM (UTC)

Amended on Sat 27 Feb 2016 12:08 PM (UTC) by Fiendish

Message

Nick Gammon said:

Fiendish said:

"Yes, but" to which statement?

This one:

Quote:

... notes sent from inside subnegotiations get automatically converted "DoAfterSpecial(0.1,..." for the noting ...

That's about what I figured. To me that means that the code change hasn't fixed the root problem and just created a second problem. Can the original change get reverted then until this is worked out?
In the back of my head I've got an idea rolling around about an intermediate message buffer to separate triggerables from notes, after I finish exploring SAPI.

https://github.com/fiendish/aardwolfclientpackage

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,208 views.

This is page 3, 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

Go to topic: Search the forum

Information and images on this site are licensed under the Creative Commons Attribution 3.0 Australia License unless stated otherwise.