eht16 / python-logstash-async

Python logging handler for sending log events asynchronously to Logstash.
MIT License
182 stars 52 forks source link

Error while using with aiohttp #53

Closed vitalerter closed 3 years ago

vitalerter commented 4 years ago

Hi i several times get this error:

base_events.py,base_events,default_exception_handler,ERROR,6,LogProcessingWorker,Task exception was never retrieved, future: <Task finished coro=<Client._misc_loop() done, defined at /usr/local/lib/python3.7/site-packages/asyncio_mqtt/client.py:309> exception=CancelledError()>, concurrent.futures._base.CancelledError

After this error the logstash not sending data to Elastic.

How to solve this? Thanks

eht16 commented 4 years ago

Can you provide more information? This library does not use aiohttp at all and I cannot see any relevance in the above error.

vitalerter commented 4 years ago

Hi, i use "python-logstash-async " library in my project in order to log data to elastic My configurations:

logstash_formatter:
            (): logstash_async.handler.LogstashFormatter
            tags:
                - localhost
            extra:
                index_name: <index>
logstash:
            level: DEBUG
            class: logstash_async.handler.AsynchronousLogstashHandler
            formatter: logstash_formatter
            host: <host>
            port: <port>
            database_path: 

Sometime i get an error, then logstash_async stop working.

base_events.py,base_events,default_exception_handler,ERROR,6,LogProcessingWorker,Task exception was never retrieved, future: <Task finished coro=<Client._misc_loop() done, defined at /usr/local/lib/python3.7/site-packages/asyncio_mqtt/client.py:309> exception=CancelledError()>, concurrent.futures._base.CancelledError

eht16 commented 3 years ago

My best guess is that there is an exception somewhere and so your application is crashing. But with the provided information I can't help more.

vitalerter commented 3 years ago

Hi,

What kind of information you need in order to help me? Thanks

eht16 commented 3 years ago

An error message, stack trace and more context or code of your application.

vitalerter commented 3 years ago

This is the error and trace:


2020-09-30 14:05:03,426,base_events.py,base_events,default_exception_handler,ERROR,6,LogProcessingWorker,Task exception was never retrieved,
2020-09-30 14:04:56,902,worker.py,worker,_safe_log_impl,ERROR,6,LogProcessingWorker,An error occurred while sending events: [Errno 111] Connection refused,
2020-09-30 14:05:01,400,worker.py,worker,_safe_log_impl,ERROR,6,LogProcessingWorker,An error occurred while sending events: [Errno 111] Connection refused,
concurrent.futures._base.CancelledError,
future: <Task finished coro=<Client._misc_loop() done, defined at /usr/local/lib/python3.7/site-packages/asyncio_mqtt/client.py:309> exception=CancelledError()>,
ConnectionRefusedError: [Errno 111] Connection refused,
    self._sock.connect((self._host, self._port)),
  File "/usr/local/lib/python3.7/site-packages/logstash_async/transport.py", line 116, in _create_socket,
    self._create_socket(),
  File "/usr/local/lib/python3.7/site-packages/logstash_async/transport.py", line 36, in send,
    self._transport.send(events, use_logging=use_logging),
  File "/usr/local/lib/python3.7/site-packages/logstash_async/worker.py", line 214, in _flush_queued_events,
    self._send_events(events),
  File "/usr/local/lib/python3.7/site-packages/logstash_async/worker.py", line 260, in _send_events,
Traceback (most recent call last):
eht16 commented 3 years ago

2020-09-30 14:05:01,400,worker.py,worker,_safe_log_impl,ERROR,6,LogProcessingWorker,An error occurred while sending events: [Errno 111] Connection refused,

This is the error and this is completely unrelated to aiohttp. Your configured Logstash endpoint is either wrong or for other reasons not reachable.

vitalerter commented 3 years ago

Sorry, the previous error occurred during endpoint reset , but today logs received at the endpoint and then i get an error and service stopped:

2020-10-04T12:27:18.113842606Z 2020-10-04 12:27:18,113,base_events.py,base_events,default_exception_handler,ERROR,6,LogProcessingWorker,Task exception was never retrieved, 2020-10-04T12:27:18.113893106Z future: <Task finished coro=<Client._misc_loop() done, defined at /usr/local/lib/python3.7/site-packages/asyncio_mqtt/client.py:309> exception=CancelledError()>

How can i get more information about this error? Thanks

eht16 commented 3 years ago

No idea. "Task exception was never retrieved" is weird, it reads like there was an exception but it is not available? I don't know your application, the configuration and what happens there. So it's hard to guess what is going wrong there.

A quick search on the net brought https://docs.python.org/3/library/asyncio-dev.html#detect-never-retrieved-exceptions which might be good to read.

vitalerter commented 3 years ago

After enable this mode:

ERROR 2020-10-06 08:59:45,835 worker 17392 19104 Log processing error (queue size: 2106490): 
Traceback (most recent call last):
  File "C:\Users\maxim\envs\cloud_device_management_env\lib\site-packages\logstash_async\worker.py", line 145, in _process_event
    self._write_event_to_database()
  File "C:\Users\maxim\envs\cloud_device_management_env\lib\site-packages\logstash_async\worker.py", line 195, in _write_event_to_database
    self._database.add_event(self._event)
  File "C:\Users\maxim\envs\cloud_device_management_env\lib\site-packages\logstash_async\database.py", line 94, in add_event
    connection.execute(query, (event, False))
MemoryError

Maybe this help you to resolve my error? Thanks

eht16 commented 3 years ago

Did you notice the MemoryError? This might be caused by the huge amount of events in the queue you have (2106490). So it seems the library cannot transmit the events to Logstash and keeps them in the queue. Either this is because of earlier errors and the queue just filled up or the transmit problem still persists. In the latter case, you should other errors before this telling about the transmission problem.

You should:

vitalerter commented 3 years ago

Hi, but I use python Logging that configured to use python-logstash-async library. How can i look for errors at DB? What if I am not use DB only in memory feature of this library ?

Hi, i use "python-logstash-async " library in my project in order to log data to elastic My configurations:

logstash_formatter:
            (): logstash_async.handler.LogstashFormatter
            tags:
                - localhost
            extra:
                index_name: <index>
logstash:
            level: DEBUG
            class: logstash_async.handler.AsynchronousLogstashHandler
            formatter: logstash_formatter
            host: <host>
            port: <port>
            database_path: 

Sometime i get an error, then logstash_async stop working.

base_events.py,base_events,default_exception_handler,ERROR,6,LogProcessingWorker,Task exception was never retrieved, future: <Task finished coro=<Client._misc_loop() done, defined at /usr/local/lib/python3.7/site-packages/asyncio_mqtt/client.py:309> exception=CancelledError()>, concurrent.futures._base.CancelledError

eht16 commented 3 years ago

When you use the in-memory database and have a queue with 2106490 events, then your host/port configuration does not work or the network connection to the Logstash host does not work. python-logstash-async tries to transmit the log events to Logstash, when the transmission failed, an appropriate message is logged and the original log event is put back in the queue for a later attempt to transmit it. This means when your queue is that huge, python-logstash-async probably couldn't successfully transmit a single event to Logstash.

I still recommend to check all logs.

You could also use a simple stripped down script to test the connection between python-logstash-async and your Logstash host (either write it yourself or take https://github.com/eht16/python-logstash-async/blob/master/example1.py as base).

Or just (temporarily) enable a SQlite database and after some time check its contents, there you should find the events which could not be transmitted as well as the log events from python-logstash-async itself which should say why the transmission failed.

vitalerter commented 3 years ago

Hi, Without DB the logs sent to Elasticsearch but with DB no message sent and the DB size was increased without errors. Also generated .db-journal file Or just (temporarily) enable a SQlite database and after some time check its contents, there you should find the events which could not be transmitted as well as the log events from python-logstash-async itself which should say why the transmission failed.

eht16 commented 3 years ago

Without DB the logs sent to Elasticsearch

I would doubt this or not all messages were sent. Even if, there must be a reason why the queue is so huge and this is likely causing the MemoryError.

with DB no message sent

You can check the events in the database and so maybe find the root cause. Use the sqlite3 command line tool or some graphical SQLite browser.

I'm not sure if I can help you with this issue at all, you don't provide much information nor helpful log messages.