[Solved] Hooking to `OnISupport` disables triggers from command 001 to 005

[Gustavo 'Gus' Carreno]

Hey Remy,

Note: Repo for reference: IRC Lob Bot

Before we continues with the debugging of the UTF8 issue, I need to inquire on another subject.

If you look at this code:

Code: Pascal  [Select][+][-]

1.   // Setup IRC Client
2.   FIRC:= TIdIRC.Create;
3.   FIRC.Nickname:= FConfig.NickName;
4.   FIRC.Username:= FConfig.UserName;
5.   FIRC.RealName:= FConfig.RealName;
6.   FIRC.Host:= FConfig.Host;
7.   FIRC.Port:= FConfig.Port;
8.   { #todo 100 -ogcarreno : Need to revisit these }
9.   //FIRC.Replies.ClientInfo:= 'PasLogBot';
10.   //FIRC.Replies.Finger:= 'paslogbot';
11.   //FIRC.Replies.UserInfo:= 'paslogbot';
12.   //FIRC.Replies.Version:= cVersion;
13.  
14.   // Events
15.   FIRC.OnConnected:= @OnConnected;
16.   FIRC.OnDisconnected:= @OnDisconnected;
17.   FIRC.OnServerQuit:= @OnServerQuit;
18.   FIRC.OnJoin:= @OnJoin;
19.   FIRC.OnNotice:= @OnNotice;
20.   FIRC.OnPrivateMessage:= @OnPrivateMessage;
21.   //FIRC.OnISupport:= @OnISupport;
22.   FIRC.OnStatus:= @OnStatus;
23.   FIRC.OnRaw:= @OnRaw;
24.   FIRC.OnBeforeCommandHandler:= @OnBeforeCommandHandler;
25.   FIRC.OnAfterCommandHandler:= @OnAfterCommandHandler;

You can have an inkling to what events I'm hooking up. And you can also notice the event I'm commenting out.
If I remove that comment, the the bot stops managing events right after the notices for the IDENT thingamajig. And what baffles me the most is that the RAW event shows the incoming RAW commands from 001 to 005 coming in, but no events reaching my code.
But if I add the comment on the OnIsupport event hook, then everything progresses fine.

I have another experimental bot, where I'm hooking to most, if not all, events and this doesn't occur. This particular bot does only one thing: For every event it logs it's occurrence and whatever data it's provided within. The only output it does is joining a channel. Nothing more.

To call the bot:

Code: Bash  [Select][+][-]

1. ./bin/paslogbot --config=pasirclogbot.example.config --debug

Can you please give me a hand with understanding this behaviour, please? I'm utterly baffled as why just adding a simple hook to an event, completely borks the command's parsing.

As per usual, I'll be eternally grateful for any help you can provide!!

Cheers,
Gus

[Remy Lebeau]

If I remove that comment, the the bot stops managing events right after the notices for the IDENT thingamajig. And what baffles me the most is that the RAW event shows the incoming RAW commands from 001 to 005 coming in, but no events reaching my code.
But if I add the comment on the OnIsupport event hook, then everything progresses fine.

Can you be more specific? Like, provide an actual example of an event that works fine with OnISupport commented out, but does not work with OnISupport uncommented?

The OnISupport event is triggered in reply to a server's 005 (RPL_ISUPPORT) notification.  It is just a notification from the server, it doesn't expect any action from the client.  So, regardless of whether you have an OnISupport event handler assigned or not, TIdIRC is always going to read the notification from the socket.  It has no effect on the rest of the IRC communication.

I'm utterly baffled as why just adding a simple hook to an event, completely borks the command's parsing.

What do you mean?  What parsing are you referring to?

[Gustavo 'Gus' Carreno]

Hey Remy,

If I remove that comment, the the bot stops managing events right after the notices for the IDENT thingamajig. And what baffles me the most is that the RAW event shows the incoming RAW commands from 001 to 005 coming in, but no events reaching my code.
But if I add the comment on the OnIsupport event hook, then everything progresses fine.

Can you be more specific? Like, provide an actual example of an event that works fine with OnISupport commented out, but does not work with OnISupport uncommented?

I thought that mentioning the project itself would allow you to get at that proof by running my IRC bot.
I'm using the version of Indy that comes from OPM.
If you run the project I mentioned on the first message, you'll only have to uncomment the appropriate line that enables the hook to OnISupport and you'll see what happens.

The OnISupport event is triggered in reply to a server's 005 (RPL_ISUPPORT) notification.  It is just a notification from the server, it doesn't expect any action from the client.  So, regardless of whether you have an OnISupport event handler assigned or not, TIdIRC is always going to read the notification from the socket.  It has no effect on the rest of the IRC communication.

I'm utterly baffled as why just adding a simple hook to an event, completely borks the command's parsing.

What do you mean?  What parsing are you referring to?

Maybe the parsing is not the problem. The problem seems to be that when those commands arrive, as shown by OnRaw, they don't trigger the appropriate hooked event.

But again, you only have to run the code on the repo I mentioned on my original message.

Cheers,
Gus

[Remy Lebeau]

I thought that mentioning the project itself would allow you to get at that proof by running my IRC bot.
I'm using the version of Indy that comes from OPM.
If you run the project I mentioned on the first message, you'll only have to uncomment the appropriate line that enables the hook to OnISupport and you'll see what happens.

Sorry, but downloading, compiling, and running your project is not an option for me.  I need you to provide details about what exactly you are experiencing.

Maybe the parsing is not the problem. The problem seems to be that when those commands arrive, as shown by OnRaw, they don't trigger the appropriate hooked event.

If you are seeing the events arrive in the OnRaw event, then there's no reason for them to not trigger their respective event handlers. There's nothing the OnISupport event can do to block subsequent events from being processed.  Something else has to be going on that you are not accounting for.

[Gustavo 'Gus' Carreno]

Hey Remy,

Sorry, but downloading, compiling, and running your project is not an option for me.  I need you to provide details about what exactly you are experiencing.

Okidokes, I can work with that!!

I got back and ran the bot with and without the hook. This time I took the opportunity to save the logs in different files so you can analyse them.

The first one withouthook.txt, demonstrates how it should work. And it's actually the version that is running with success at the moment.
The second one withhook.txt should've demonstrated it not working, but somehow it did. More on this later.
The third one withhook-notworking.txt is what I get after running the bot a second time, or any other time with almost no interval.

Ok, first observation is this: I only get debug info on After Command, never on Before Command, and that is strange.
Second observation: With the hook, when it worked, the event was never fired since I don't get the messages on all three 005 commands, or even a single one with all collected data.
Third observation: WIth the hook on and when it doesn't work, after getting the first OnRaw of 005, I get nothing more. The bot just stops receiving any other event.

I'm not sure it's a timing thing. Especially when everytime I restart the bot without the hook, I never get a different outcome. It just works the same every time.
But when I add the hook, I'm now seeing two completely different behaviours and that is even more frustrating than it not working every time ARGH!!!!

Please have a good look at the log files and then, if you can, please give me stuff to do in order to better explain what could be happening here.

Cheers,
Gus

[Remy Lebeau]

I notice that your OnISupport handler is passing a TStrings object pointer in the '%s' specifier of your debug() function.

When I look at your logging code in irclogbot.common.pas, I see that debug() is simply passing its parameters as-is to SysUtils.Format(), which does not support formatting a class object for the '%s' specifier.  It will raise an EConvertError exception, which you are not catching.  If an exception escapes an event handler back into TIdIRC, its internal reading thread will be terminated.  That would explain why you are not seeing any further events.

The '%s' specifier of SysUtils.Format() allows only string types and also Variant, nothing else.  So, you need to change the following statement in your OnISupport handler:

debug('I Support: %s', [AParameters]);

To this instead:

debug('I Support: %s', [AParameters.Text]);

How this could EVER have worked is a mystery.  It should have failed EVERY time.

[Gustavo 'Gus' Carreno]

Hey Remy,

It will raise an EConvertError exception, which you are not catching.  If an exception escapes an event handler back into TIdIRC, its internal reading thread will be terminated.  That would explain why you are not seeing any further events.

AH-HA !!! This makes enormous sense now !!!
That explains why the entire TIdIRC collapses but not my app.
What baffles me is that there's no Exception bubbling up.... Unless... I usually turn off the Exception handling of TCustomApplication...
That may explain why nothing goes boom immediately... OK, I need to do some tests with the Exception handling turned on...

How this could EVER have worked is a mystery.  It should have failed EVERY time.

I agree!! I'll ping you back when I test with the Exception handling turned back.
The entire thing being wrapped in a TCustomApplication gives us another level of abstraction that sometimes we forget is even there.

Thanks my good friend for noticing something soo, soooo obvious that it completely escaped me. It's a rather DOH!! moment, ROTFL

I'll correct the stupid error. Test the Exception handling. Then I'll report back.
Once this is finished, we'll then get into the meat of the `UTF8` thang!!

And again, I cannot thank you enough for the time you've spent debugging my stupid code

Cheers,
Gus

[Remy Lebeau]

What baffles me is that there's no Exception bubbling up.... Unless... I usually turn off the Exception handling of TCustomApplication...

Since the exception is occurring in a worker thread inside of TIdIRC, I don't think it would get reported by TCustomApplication.

Funny thing, the TIdCommandHandlers collection does have an OnCommandHandlersException event, but it's not actually hooked up right now (I wonder why not?), not that it matters because the only component that even tries to use it is TIdIMAP4 for its OnCommandError event.

[Gustavo 'Gus' Carreno]

Hey Remy,

What baffles me is that there's no Exception bubbling up.... Unless... I usually turn off the Exception handling of TCustomApplication...

Since the exception is occurring in a worker thread inside of TIdIRC, I don't think it would get reported by TCustomApplication.

Hummm... Somehow, that kinda strikes me as a bit of bad design. I think...
Welp, kinda. I've done some threading code myself, and I've manage to loose Exceptions on those thread.
In a way it makes sense. The thread is not called, so it can't go up on anything. Yeah... I see it now!

Funny thing, the TIdCommandHandlers collection does have an OnCommandHandlersException event, but it's not actually hooked up right now (I wonder why not?), not that it matters because the only component that even tries to use it is TIdIMAP4 for its OnCommandError event.

Humm, that is quite odd indeed. Is there something that should be done about that?
Have we found a bit of an oversight in Indy's code that was missed or forgotten?
UUUUHHH, ancient code spelunken... Interesting. LOL!!!

Welp, I'll leave you to decide what should be done. I'll do my best to get my side of things back working!!

Cheers,
Gus

[Gustavo 'Gus' Carreno]

Hey Remy,

I've made the fix on the bot. It now works as intended !! Cannot thank you enough for that !!

I'll now switch to the other thread where we're dealing with the UTF8 thing.
I'll elaborate more there on that subject.

Cheers,
Gus