[Intelmq-users] Bots stopping

Vaclav Bruzek vasek.bruzek at gmail.com
Thu Oct 11 08:50:32 CEST 2018 

Sorry, I've managed to send mail early without the exception and the
attachment. Here is the last line of the log I wanted to add.

2018-10-08 07:24:01,332 - whitelist-output - INFO - WhitelistOutputBot
initialized with id whitelist-output and intelmq 1.1.0 and python 3.6.5
(default, Apr  1 2018, 05:46:30) as process 1150.

Sincerely,
Václav Brůžek


On Thu, 11 Oct 2018 at 08:47, Vaclav Bruzek <vasek.bruzek at gmail.com> wrote:

> Hi Sebastian,
> I've added the Redis exception to the attachment. That is the case that I
> would expect that the bot would keep trying to connect to Redis and not
> give up and exit.
>
> I use continuous run mode for all bots.
>
> I've also extracted the example of the other behaviour, that is exiting
> without logging that the bot stopped. That is indeed what I meant (your
> last point), that the bot logs the exception but doesn't log the line "Bot
> stopped" and stops, which is what status check is reproting.
> ¨
> 2018-10-02 02:43:13,744 - output - ERROR - Bot has found a problem.
> Traceback (most recent call last):
>   File
> "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0-py3.6.egg/intelmq/lib/bot.py",
> line 167, in start
>     self.process()
>   File
> "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0-py3.6.egg/intelmq/bots/outputs/bot/output.py",
> line 67, in process
>     status = self.db_check()
>   File
> "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0-py3.6.egg/intelmq/bots/outputs/bot/output.py",
> line 53, in db_check
>     payload = self.connection_blacklist.get(key).decode("utf-8",
> errors="ignore")
> AttributeError: 'NoneType' object has no attribute 'decode'
> 2018-10-02 02:43:13,744 - output - INFO - Current Message(event): {"some
> event"}.
> 2018-10-02 02:43:13,745 - output - INFO - Bot will continue in 0 seconds.
> 2018-10-02 02:43:35,997 - whitelist-output - ERROR - Bot has found a
> problem.
> Traceback (most recent call last):
>
> AttributeError: 'NoneType' object has no attribute 'decode'
> 2018-10-02 02:43:35,998 - whitelist-output - INFO - Current
> Message(event): {'feed.accuracy': 100.0, 'feed.name': 'whalebone',
> 'feed.url': 'http://wb-whitelist.azurewebsites.net/whitelist.txt',
> 'time.observation': '2018-10-02T02:41:58+00:00', 'source.fqdn': 'com.bd',
> 'raw': 'Y29tLmJkDQo='}.
> 2018-10-02 02:43:35,998 - whitelist-output - INFO - Dumping message from
> pipeline to dump file.
>
>
> Sincerely,
> Václav Brůžek
>
>
> On Wed, 10 Oct 2018 at 15:36, Sebastian Wagner <wagner at cert.at> wrote:
>
>> Hi Václav,
>>
>> I can't estimate the implications of the docker usage on redis and
>> intelmq.
>>
>> Concerning the redis problem: There were no changes in the code handling
>> redis problems and the only case when intelmq's bots do not log anything is
>> when there are not enough resources to shutdown cleanly (memory, disk).
>> Even then, there's output on stdout. You could log stdout and see if there
>> are any errors shown at the end.
>>
>> Concerning the error handling and sudden stops: There haven't been code
>> changes too. Do you use the scheduled run mode? If the error_procedure is
>> pass and there are pipeline problems, the bot stops (in bot.py search for
>> "error_procedure: pass and pipeline problem"). AFAIR the reasoning for this
>> was/is that if the bot would not stop, the pipeline would be kind of
>> DOS'ed. But as problems with memory and snapshots in redis are handled
>> better now, that could be relaxed. I'll do some experiments.
>>
>> Concerning "encounters an exception and logs nothing but status check
>> reports that the bot is not running": How do you know that the bot
>> encountered an exception if nothing is logged? Is the bot then still
>> running or not?
>>
>> Sebastian
>> On 09/10/2018 12.58, Vaclav Bruzek wrote:
>>
>> Hi,
>> no there are no modification to the intelmq code. The situation occurs at
>> my custom bots as well as the default ones. As an example of this
>> behaviour: recently Redis broker wasn't available for some time, as a
>> result almost all bots stopped without any log message indicating that the
>> bot stopped.
>>
>> Sincerely,
>> Václav Brůžek
>>
>>
>> On Tue, 9 Oct 2018 at 12:01, Sebastian Wagner <wagner at cert.at> wrote:
>>
>>> Hi,
>>>
>>> I didn't know of any problems yet. Do you use any custom modifications
>>> in the code? If yes, which?
>>>
>>> Sebastian
>>> On 09/10/2018 10.42, Vaclav Bruzek wrote:
>>>
>>> Hi,
>>> since upgrading to version 1.1.0 it became quite a big problem the
>>> stability of bots. Often it happens that bot encounters an exception and
>>> logs that the bot is stopped or encounters an exception and logs nothing
>>> but status check reports that the bot is not running. I'm using the
>>> 'error_procedure' parameter set to 'pass' (with error_max_retries
>>> and error_retry_delay set to 0) and I've always thought that this is a sort
>>> of 'run forever' parameter that even when exception occurs the bot will
>>> keep on doing its job. I'm using intelmq in Docker environment with ubuntu
>>> 18.04 as base.
>>>
>>> Sincerely,
>>> Václav Brůžek
>>>
>>> --
>>> // Sebastian Wagner <wagner at cert.at> <wagner at cert.at> - T: +43 1 5056416 7201
>>> // CERT Austria - https://www.cert.at/
>>> // Eine Initiative der nic.at GmbH - https://www.nic.at/
>>> // Firmenbuchnummer 172568b, LG Salzburg
>>>
>>> --
>> // Sebastian Wagner <wagner at cert.at> <wagner at cert.at> - T: +43 1 5056416 7201
>> // CERT Austria - https://www.cert.at/
>> // Eine Initiative der nic.at GmbH - https://www.nic.at/
>> // Firmenbuchnummer 172568b, LG Salzburg
>>
>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.cert.at/pipermail/intelmq-users/attachments/20181011/c4884e31/attachment.html>
-------------- next part --------------
2018-10-05 13:21:25,677 - xyz-parser - INFO - Pipeline ready.
2018-10-05 13:21:32,930 - xyz-parser - ERROR - Pipeline failed.
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/redis/client.py", line 668, in execute_command
    return self.parse_response(connection, command_name, **options)
  File "/usr/local/lib/python3.6/dist-packages/redis/client.py", line 680, in parse_response
    response = connection.read_response()
  File "/usr/local/lib/python3.6/dist-packages/redis/connection.py", line 624, in read_response
    response = self._parser.read_response()
  File "/usr/local/lib/python3.6/dist-packages/redis/connection.py", line 301, in read_response
    raise error
redis.exceptions.BusyLoadingError: Redis is loading the dataset in memory

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0a1-py3.6.egg/intelmq/lib/pipeline.py", line 148, in receive
    retval = self.pipe.lindex(self.internal_queue, -1)  # returns None if no value
  File "/usr/local/lib/python3.6/dist-packages/redis/client.py", line 1311, in lindex
    return self.execute_command('LINDEX', name, index)
  File "/usr/local/lib/python3.6/dist-packages/redis/client.py", line 674, in execute_command
    return self.parse_response(connection, command_name, **options)
  File "/usr/local/lib/python3.6/dist-packages/redis/client.py", line 680, in parse_response
    response = connection.read_response()
  File "/usr/local/lib/python3.6/dist-packages/redis/connection.py", line 624, in read_response
    response = self._parser.read_response()
  File "/usr/local/lib/python3.6/dist-packages/redis/connection.py", line 301, in read_response
    raise error
redis.exceptions.BusyLoadingError: Redis is loading the dataset in memory

During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0a1-py3.6.egg/intelmq/lib/bot.py", line 163, in start
    self.process()
  File "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0a1-py3.6.egg/intelmq/lib/bot.py", line 673, in process
    report = self.receive_message()
  File "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0a1-py3.6.egg/intelmq/lib/bot.py", line 378, in receive_message
    message = self.__source_pipeline.receive()
  File "/usr/local/lib/python3.6/dist-packages/intelmq-1.1.0a1-py3.6.egg/intelmq/lib/pipeline.py", line 154, in receive
    raise exceptions.PipelineError(exc)
intelmq.lib.exceptions.PipelineError: pipeline failed - BusyLoadingError('Redis is loading the dataset in memory',)
2018-10-05 13:21:32,959 - xyz--parser - INFO - Processed 365 messages since last logging.
2018-10-05 13:21:32,974 - xyz-parser - INFO - Bot stopped.

More information about the Intelmq-users mailing list