Hi all,
Tracking down a rather elusive bug led me to suspect that the command
intelmqctl reload your_bot_name_here
does not necessarily rerun the bot's init method. At least I see an exception related to undefined variables (NoneType) when I reload the bot in question and let it chew a new event. Is this expected behaviour? Still, skimming through the code, it seems to me that the __init__ method in lib/bot.py gets invoked and should invoke the bot's init method as well.
Any hints/ideas?
Br, Mika
Hi Mika,
On 6/22/22 1:58 PM, Mika Silander wrote:
Tracking down a rather elusive bug led me to suspect that the command
intelmqctl reload your_bot_name_here
does not necessarily rerun the bot's init method.
It does, but not directly.
reloading relies on sending a signal to the process. But signals interrupt system calls, which is normally not an issue, except the process is currently doing something on the network, more specifically with the pipeline (sending or receiving data). Let's assume that the bot sends an event to redis, get's interrupted. What to do now? Run init, and then? we can't just resume the previously running process() call. Therefore, the behaviour is not completely straighforward, but not magic. The signal is caught (__handle_sighup_signal) and python is commanded to resume system calls instead of interrupted (signal.siginterrupt(signal.SIGHUP, False) in __init__) Once there is time to handle the reload safely (before/after process, during sleeps, when waiting for messages), the bot is actually reloaded and __init__ called (__handle_sighup).
At least I see an exception related to undefined variables (NoneType)
In the code of the core or in the bot's code? If it's the bot's code: What bot is it? In any case, the stacktrace helps in explaining the issue, because unfortunately crystal ball broke last night when my neighbors' dragon chased my little dinosaur....
when I reload the bot in question and let it chew a new event. Is this expected behaviour? Still, skimming through the code, it seems to me that the __init__ method in lib/bot.py gets invoked and should invoke the bot's init method as well.
Yes, it shoud/does:
https://github.com/certtools/intelmq/blob/79cae294a74ab77f09b1f371a19f04ad65...
Hi Sebastian,
Thanks for a prompt response. And yes, I was not very generous concerning details, so here's a hopefully better description:
I have an expert bot of my own that I start normally and then reload it with intelmqctl reload. When I now push an event to it for processing, a message appears in the log saying
"TypeError: 'NoneType' object is not subscriptable"
This is due to a variable (dict) becoming undefined in the reload. During a normal start this variable gets however, properly initiated once the first event comes in for processing. The reason for its initiation in the process method arises from the need to regularly update it from a file that changes occasionally. In other words, my bot's init method sets this variable to None and if it is None when reaching the bot's process method, it gets initialised there before any accesses to it. Later accesses/updates to this variable are successful unless I reload the bot.
In a reload, my bot's log starts with:
INFO - Received SIGHUP, initializin g again later. INFO - Handling SIGHUP, initializing again now.
which leads me to assume that any possible delay needed ahead of a safe reload has passed and the reload can in fact take place as you describe below. There are indications that the Bot::__init__ (from intelmq/lib/bot.py) is run as the lines:
INFO - Bot is starting. INFO - Bot initialization completed.
also show up in the bot's log. No log message from my bot's own init method gets written in between the above two, which leads me to assume that my bot's init method is not run, right? But shouldn't it be?
Thanks again, Mika
From: "Sebix" sebix@sebix.at To: "Mika Silander" mika.silander@csc.fi, "intelmq-dev" intelmq-dev@lists.cert.at Sent: Wednesday, 22 June, 2022 15:15:20 Subject: Re: [IntelMQ-dev] Expected behaviour of intelmqctl reload ?
Hi Mika, On 6/22/22 1:58 PM, Mika Silander wrote:
Tracking down a rather elusive bug led me to suspect that the command
intelmqctl reload your_bot_name_here
does not necessarily rerun the bot's init method.
It does, but not directly.
reloading relies on sending a signal to the process. But signals interrupt system calls, which is normally not an issue, except the process is currently doing something on the network, more specifically with the pipeline (sending or receiving data). Let's assume that the bot sends an event to redis, get's interrupted. What to do now? Run init, and then? we can't just resume the previously running process() call. Therefore, the behaviour is not completely straighforward, but not magic. The signal is caught ( __handle_sighup_signal) and python is commanded to resume system calls instead of interrupted ( signal . siginterrupt ( signal . SIGHUP , False ) in __init__) Once there is time to handle the reload safely (before/after process, during sleeps, when waiting for messages), the bot is actually reloaded and __init__ called ( __handle_sighup). BQ_BEGIN
At least I see an exception related to undefined variables (NoneType)
BQ_END In the code of the core or in the bot's code? If it's the bot's code: What bot is it? In any case, the stacktrace helps in explaining the issue, because unfortunately crystal ball broke last night when my neighbors' dragon chased my little dinosaur....
BQ_BEGIN
when I reload the bot in question and let it chew a new event. Is this expected behaviour? Still, skimming through the code, it seems to me that the __init__ method in lib/bot.py gets invoked and should invoke the bot's init method as well.
BQ_END
Yes, it shoud/does:
[ https://github.com/certtools/intelmq/blob/79cae294a74ab77f09b1f371a19f04ad65... | https://github.com/certtools/intelmq/blob/79cae294a74ab77f09b1f371a19f04ad65... ] BQ_BEGIN
BQ_END
Hi all,
I managed to isolate and solve the below problem yesterday and share some details here so that you won't fall in the same trap. The root cause is I didn't fully understand how bot reloading works. Here's some pseudo-code explaining the problem in my expert bot implementation. First the initial implementation:
class MyExpertBot(Bot):
def init(self): self.dataconstruct = None
def process(self): if self.dataconstruct is None:
From: "Mika Silander" mika.silander@csc.fi To: "intelmq-dev" intelmq-dev@lists.cert.at Sent: Wednesday, 22 June, 2022 15:59:11 Subject: Re: [IntelMQ-dev] Expected behaviour of intelmqctl reload ?
Hi Sebastian,
Thanks for a prompt response. And yes, I was not very generous concerning details, so here's a hopefully better description:
I have an expert bot of my own that I start normally and then reload it with intelmqctl reload. When I now push an event to it for processing, a message appears in the log saying
"TypeError: 'NoneType' object is not subscriptable"
This is due to a variable (dict) becoming undefined in the reload. During a normal start this variable gets however, properly initiated once the first event comes in for processing. The reason for its initiation in the process method arises from the need to regularly update it from a file that changes occasionally. In other words, my bot's init method sets this variable to None and if it is None when reaching the bot's process method, it gets initialised there before any accesses to it. Later accesses/updates to this variable are successful unless I reload the bot.
In a reload, my bot's log starts with:
INFO - Received SIGHUP, initializin g again later. INFO - Handling SIGHUP, initializing again now.
which leads me to assume that any possible delay needed ahead of a safe reload has passed and the reload can in fact take place as you describe below. There are indications that the Bot::__init__ (from intelmq/lib/bot.py) is run as the lines:
INFO - Bot is starting. INFO - Bot initialization completed.
also show up in the bot's log. No log message from my bot's own init method gets written in between the above two, which leads me to assume that my bot's init method is not run, right? But shouldn't it be?
Thanks again, Mika
From: "Sebix" sebix@sebix.at To: "Mika Silander" mika.silander@csc.fi, "intelmq-dev" intelmq-dev@lists.cert.at Sent: Wednesday, 22 June, 2022 15:15:20 Subject: Re: [IntelMQ-dev] Expected behaviour of intelmqctl reload ?
Hi Mika, On 6/22/22 1:58 PM, Mika Silander wrote:
Tracking down a rather elusive bug led me to suspect that the command
intelmqctl reload your_bot_name_here
does not necessarily rerun the bot's init method.
It does, but not directly.
reloading relies on sending a signal to the process. But signals interrupt system calls, which is normally not an issue, except the process is currently doing something on the network, more specifically with the pipeline (sending or receiving data). Let's assume that the bot sends an event to redis, get's interrupted. What to do now? Run init, and then? we can't just resume the previously running process() call. Therefore, the behaviour is not completely straighforward, but not magic. The signal is caught ( __handle_sighup_signal) and python is commanded to resume system calls instead of interrupted ( signal . siginterrupt ( signal . SIGHUP , False ) in __init__) Once there is time to handle the reload safely (before/after process, during sleeps, when waiting for messages), the bot is actually reloaded and __init__ called ( __handle_sighup). BQ_BEGIN
At least I see an exception related to undefined variables (NoneType)
BQ_END In the code of the core or in the bot's code? If it's the bot's code: What bot is it? In any case, the stacktrace helps in explaining the issue, because unfortunately crystal ball broke last night when my neighbors' dragon chased my little dinosaur....
BQ_BEGIN
when I reload the bot in question and let it chew a new event. Is this expected behaviour? Still, skimming through the code, it seems to me that the __init__ method in lib/bot.py gets invoked and should invoke the bot's init method as well.
BQ_END
Yes, it shoud/does:
[ https://github.com/certtools/intelmq/blob/79cae294a74ab77f09b1f371a19f04ad65... | https://github.com/certtools/intelmq/blob/79cae294a74ab77f09b1f371a19f04ad65... ] BQ_BEGIN
BQ_END
Hi again,
Dang ... mistyping and the unfinished message went off. A new try:
I managed to isolate and solve the below problem yesterday and share some details here so that you won't fall in the same trap. The root cause is I didn't fully understand how bot reloading works. Here's some pseudo-code explaining the problem in my expert bot implementation. First the initial implementation:
class MyExpertBot(Bot):
def init(self): self.dataconstruct = None
def process(self): if self.dataconstruct is None or is_too_old(self.dataconstruct): # initiate/update the construct here event = self.receive_message() # Access the data within self.dataconstruct here to process the event ...
Then the fixed process method:
def process(self): event = self.receive_message() if self.dataconstruct is None or is_too_old(self.dataconstruct): # initiate/update the construct here # Access the data within self.dataconstruct here to process the event ...
Both versions work fine as long as you don't reload the bot. Reloading of the first version will however, reset self.dataconstruct to None while we are waiting for a new event. Once we receive the event, accesses to self.dataconstruct will of course fail. The latter version in turn, survives the reload since self.dataconstruct gets reinitiated _after_ the event is received. It took some time to realise the reload is specified in /etc/logrotate.d/intelmq (silly me).
Finally, the usual request: correct me if my interpretation above is wrong.
Best regards, Mika
From: "Mika Silander" mika.silander@csc.fi To: "intelmq-dev" intelmq-dev@lists.cert.at Sent: Thursday, 23 June, 2022 07:53:52 Subject: Re: [IntelMQ-dev] Expected behaviour of intelmqctl reload ?
Hi all,
I managed to isolate and solve the below problem yesterday and share some details here so that you won't fall in the same trap. The root cause is I didn't fully understand how bot reloading works. Here's some pseudo-code explaining the problem in my expert bot implementation. First the initial implementation:
class MyExpertBot(Bot):
def init(self): self.dataconstruct = None
def process(self): if self.dataconstruct is None:
From: "Mika Silander" mika.silander@csc.fi To: "intelmq-dev" intelmq-dev@lists.cert.at Sent: Wednesday, 22 June, 2022 15:59:11 Subject: Re: [IntelMQ-dev] Expected behaviour of intelmqctl reload ?
Hi Sebastian,
Thanks for a prompt response. And yes, I was not very generous concerning details, so here's a hopefully better description:
I have an expert bot of my own that I start normally and then reload it with intelmqctl reload. When I now push an event to it for processing, a message appears in the log saying
"TypeError: 'NoneType' object is not subscriptable"
This is due to a variable (dict) becoming undefined in the reload. During a normal start this variable gets however, properly initiated once the first event comes in for processing. The reason for its initiation in the process method arises from the need to regularly update it from a file that changes occasionally. In other words, my bot's init method sets this variable to None and if it is None when reaching the bot's process method, it gets initialised there before any accesses to it. Later accesses/updates to this variable are successful unless I reload the bot.
In a reload, my bot's log starts with:
INFO - Received SIGHUP, initializin g again later. INFO - Handling SIGHUP, initializing again now.
which leads me to assume that any possible delay needed ahead of a safe reload has passed and the reload can in fact take place as you describe below. There are indications that the Bot::__init__ (from intelmq/lib/bot.py) is run as the lines:
INFO - Bot is starting. INFO - Bot initialization completed.
also show up in the bot's log. No log message from my bot's own init method gets written in between the above two, which leads me to assume that my bot's init method is not run, right? But shouldn't it be?
Thanks again, Mika
From: "Sebix" sebix@sebix.at To: "Mika Silander" mika.silander@csc.fi, "intelmq-dev" intelmq-dev@lists.cert.at Sent: Wednesday, 22 June, 2022 15:15:20 Subject: Re: [IntelMQ-dev] Expected behaviour of intelmqctl reload ?
Hi Mika, On 6/22/22 1:58 PM, Mika Silander wrote:
Tracking down a rather elusive bug led me to suspect that the command
intelmqctl reload your_bot_name_here
does not necessarily rerun the bot's init method.
It does, but not directly.
reloading relies on sending a signal to the process. But signals interrupt system calls, which is normally not an issue, except the process is currently doing something on the network, more specifically with the pipeline (sending or receiving data). Let's assume that the bot sends an event to redis, get's interrupted. What to do now? Run init, and then? we can't just resume the previously running process() call. Therefore, the behaviour is not completely straighforward, but not magic. The signal is caught ( __handle_sighup_signal) and python is commanded to resume system calls instead of interrupted ( signal . siginterrupt ( signal . SIGHUP , False ) in __init__) Once there is time to handle the reload safely (before/after process, during sleeps, when waiting for messages), the bot is actually reloaded and __init__ called ( __handle_sighup). BQ_BEGIN
At least I see an exception related to undefined variables (NoneType)
BQ_END In the code of the core or in the bot's code? If it's the bot's code: What bot is it? In any case, the stacktrace helps in explaining the issue, because unfortunately crystal ball broke last night when my neighbors' dragon chased my little dinosaur....
BQ_BEGIN
when I reload the bot in question and let it chew a new event. Is this expected behaviour? Still, skimming through the code, it seems to me that the __init__ method in lib/bot.py gets invoked and should invoke the bot's init method as well.
BQ_END
Yes, it shoud/does:
[ https://github.com/certtools/intelmq/blob/79cae294a74ab77f09b1f371a19f04ad65... | https://github.com/certtools/intelmq/blob/79cae294a74ab77f09b1f371a19f04ad65... ] BQ_BEGIN
BQ_END