tradingview-webhooks-bot icon indicating copy to clipboard operation
tradingview-webhooks-bot copied to clipboard

Published 20 hours ago • verified publisher icon robswc

Worker timeout

Open robswc opened this issue 2 years ago • 9 comments

Happens when /webhook request can't be processed in time. Can be from various causes. Investigating...

robswc avatar Sep 26 '22 21:09 robswc

You did a great Tool !!!

But this timeout thing is really bad - any workaround for this maybe?

tlnet1981 avatar Oct 12 '22 15:10 tlnet1981

Hey! So there could be several reasons for this, depending on the logic of the run method. Are you able to paste in (omitting any personal information) your run method? I can take a look at it! @tlnet1981

The issue is more or less:

Signal Gets to Action/Event Stuff is being done Stuff doesn't finish in time Time out

The "stuff" could be stuck somewhere. I will be adding a "timeout" option to increase the default timeout time to something more than 30 seconds. (usually more than this amount of time indicates an issue though)

robswc avatar Oct 12 '22 15:10 robswc

Hi! thanks for all that :)

I found the same workaround: in line 62 i added a timeout to the server with 1 second:

run(f'gunicorn --bind {host}:{port} --timeout 1 wsgi:app'.split(' '))

As i set the timeout to 600, it wouldnt time out again, but the stuckness every about 30 seconds (meaning taking no new webhooks) remained.

with 1 second, it reboots often but is therefore more available because stuckness is limited to one second. doesnt solve the root cause though..

tlnet1981 avatar Oct 12 '22 17:10 tlnet1981

Hmm, in that case, I may try to change actions to be run with async. This should solve any timeout issues going forward!

You can "emulate" this by using multi threading for now if you wish. Something like this: https://superfastpython.com/run-function-in-new-thread/

Are you able to locate where in your run method the script is taking a long time?

robswc avatar Oct 12 '22 17:10 robswc

I am totally not able to locate that :D I can only tell you that the webhook logic functions very fast and well, until after about 30 seconds it doesn react anymore at all until it reboots or some time passes by and it will eventually react again

tlnet1981 avatar Oct 12 '22 18:10 tlnet1981

@tlnet1981 interesting! Well, if its possible to paste your run method here (without any of your personal details) I can take a look at it and see if there's anything we can do to fix it :)

It's also ok if you're fine with how its working now.

robswc avatar Oct 12 '22 19:10 robswc

@robswc , sorry didnt understand you right - you mean the code of my "action" - sure no problem. I basically just pump it to a redis channel, and other stuff is picking it up from there:

`class test(Action): def init(self): super().init()

def run(self, *args, **kwargs):
    super().run(*args, **kwargs)  # this is required
    data = self.validate_data()  # always get data from webhook by calling this method!
    print('Data from webhook:', data)
    r = redis.Redis(host='localhost', port=6379, db=0)
    r.publish('tradingview', json.dumps(data))
    print(self.name, '---> action has run!')`

you mean the redis server is causing the delays? ...but the worker timeout or stuckness appears also during times when no webhook comes an, therefore no action is triggered.

tlnet1981 avatar Oct 13 '22 06:10 tlnet1981

here you can see, no action triggered but reboots all the time (1 second timeout)

...pretty exactly every 1 minute

2022-10-13 02:06:33,869 [MainThread ] [INFO ] Registering action ---> test 2022-10-13 02:06:33,948 [MainThread ] [DEBUG] Imported action module ---> test 2022-10-13 02:06:33,948 [MainThread ] [INFO ] ACTION REGISTERED ---> test 2022-10-13 02:06:33,948 [MainThread ] [INFO ] Action "test" registered successfully! 2022-10-13 02:06:33,948 [MainThread ] [INFO ] Registering event ---> WebhookReceived 2022-10-13 02:06:33,992 [MainThread ] [DEBUG] Imported event module ---> webhook_received 2022-10-13 02:06:33,993 [MainThread ] [INFO ] Event "WebhookReceived" registered successfully! 2022-10-13 02:06:33,993 [MainThread ] [INFO ] Link "test -> WebhookReceived" registered successfully! [2022-10-13 02:07:38 +0200] [23789] [CRITICAL] WORKER TIMEOUT (pid:24885) [2022-10-13 02:07:38 +0200] [24885] [INFO] Worker exiting (pid: 24885) [2022-10-13 02:07:38 +0200] [24886] [INFO] Booting worker with pid: 24886 2022-10-13 02:07:39,279 [MainThread ] [INFO ] Registering action ---> test 2022-10-13 02:07:39,353 [MainThread ] [DEBUG] Imported action module ---> test 2022-10-13 02:07:39,353 [MainThread ] [INFO ] ACTION REGISTERED ---> test 2022-10-13 02:07:39,353 [MainThread ] [INFO ] Action "test" registered successfully! 2022-10-13 02:07:39,353 [MainThread ] [INFO ] Registering event ---> WebhookReceived 2022-10-13 02:07:39,395 [MainThread ] [DEBUG] Imported event module ---> webhook_received 2022-10-13 02:07:39,395 [MainThread ] [INFO ] Event "WebhookReceived" registered successfully! 2022-10-13 02:07:39,395 [MainThread ] [INFO ] Link "test -> WebhookReceived" registered successfully! [2022-10-13 02:08:42 +0200] [23789] [CRITICAL] WORKER TIMEOUT (pid:24886) [2022-10-13 02:08:42 +0200] [24886] [INFO] Worker exiting (pid: 24886) [2022-10-13 02:08:42 +0200] [24887] [INFO] Booting worker with pid: 24887 2022-10-13 02:08:43,677 [MainThread ] [INFO ] Registering action ---> test 2022-10-13 02:08:43,753 [MainThread ] [DEBUG] Imported action module ---> test 2022-10-13 02:08:43,753 [MainThread ] [INFO ] ACTION REGISTERED ---> test 2022-10-13 02:08:43,753 [MainThread ] [INFO ] Action "test" registered successfully! 2022-10-13 02:08:43,753 [MainThread ] [INFO ] Registering event ---> WebhookReceived 2022-10-13 02:08:43,794 [MainThread ] [DEBUG] Imported event module ---> webhook_received 2022-10-13 02:08:43,794 [MainThread ] [INFO ] Event "WebhookReceived" registered successfully! 2022-10-13 02:08:43,794 [MainThread ] [INFO ] Link "test -> WebhookReceived" registered successfully! [2022-10-13 02:09:48 +0200] [23789] [CRITICAL] WORKER TIMEOUT (pid:24887) [2022-10-13 02:09:48 +0200] [24887] [INFO] Worker exiting (pid: 24887) [2022-10-13 02:09:48 +0200] [24888] [INFO] Booting worker with pid: 24888 2022-10-13 02:09:49,252 [MainThread ] [INFO ] Registering action ---> test 2022-10-13 02:09:49,331 [MainThread ] [DEBUG] Imported action module ---> test 2022-10-13 02:09:49,331 [MainThread ] [INFO ] ACTION REGISTERED ---> test 2022-10-13 02:09:49,331 [MainThread ] [INFO ] Action "test" registered successfully! 2022-10-13 02:09:49,331 [MainThread ] [INFO ] Registering event ---> WebhookReceived 2022-10-13 02:09:49,381 [MainThread ] [DEBUG] Imported event module ---> webhook_received 2022-10-13 02:09:49,381 [MainThread ] [INFO ] Event "WebhookReceived" registered successfully! 2022-10-13 02:09:49,381 [MainThread ] [INFO ] Link "test -> WebhookReceived" registered successfully! [2022-10-13 02:10:53 +0200] [23789] [CRITICAL] WORKER TIMEOUT (pid:24888) [2022-10-13 02:10:53 +0200] [24888] [INFO] Worker exiting (pid: 24888) [2022-10-13 02:10:53 +0200] [24889] [INFO] Booting worker with pid: 24889 2022-10-13 02:10:53,948 [MainThread ] [INFO ] Registering action ---> test 2022-10-13 02:10:54,025 [MainThread ] [DEBUG] Imported action module ---> test 2022-10-13 02:10:54,026 [MainThread ] [INFO ] ACTION REGISTERED ---> test 2022-10-13 02:10:54,026 [MainThread ] [INFO ] Action "test" registered successfully! 2022-10-13 02:10:54,026 [MainThread ] [INFO ] Registering event ---> WebhookReceived 2022-10-13 02:10:54,064 [MainThread ] [DEBUG] Imported event module ---> webhook_received 2022-10-13 02:10:54,064 [MainThread ] [INFO ] Event "WebhookReceived" registered successfully! 2022-10-13 02:10:54,064 [MainThread ] [INFO ] Link "test -> WebhookReceived" registered successfully! [2022-10-13 02:11:58 +0200] [23789] [CRITICAL] WORKER TIMEOUT (pid:24889) [2022-10-13 02:11:58 +0200] [24889] [INFO] Worker exiting (pid: 24889) [2022-10-13 02:11:58 +0200] [24890] [INFO] Booting worker with pid: 24890

tlnet1981 avatar Oct 13 '22 06:10 tlnet1981

@robswc Is there an update on this issue? I saw an async commit but 1.0.2 did not solve the problem.

Here is my log without any changes on my side:

GUI` is set to [CLOSED] - it will be served at the path /?guiKey=<unique_key> View GUI dashboard here: http://0.0.0.0:5000?guiKey= To run the GUI in [OPEN] mode (for development purposes only), run the following command: tvwb start --open-gui To learn more about GUI modes, visit: https://github.com/robswc/tradingview-webhooks-bot/discussions/43 Close server with Ctrl+C in terminal. [2024-03-11 14:17:22 +0000] [7] [INFO] Starting gunicorn 20.1.0 [2024-03-11 14:17:22 +0000] [7] [INFO] Listening at: http://0.0.0.0:5000 (7) [2024-03-11 14:17:22 +0000] [7] [INFO] Using worker: sync [2024-03-11 14:17:22 +0000] [8] [INFO] Booting worker with pid: 8 2024-03-11 14:17:22,946 [MainThread ] [INFO ] Registering action ---> PrintData 2024-03-11 14:17:22,948 [MainThread ] [DEBUG] Imported action module ---> print_data 2024-03-11 14:17:22,948 [MainThread ] [INFO ] ACTION REGISTERED ---> PrintData 2024-03-11 14:17:22,948 [MainThread ] [INFO ] Action "PrintData" registered successfully! 2024-03-11 14:17:22,948 [MainThread ] [INFO ] Registering action ---> AsyncDemo 2024-03-11 14:17:22,950 [MainThread ] [DEBUG] Imported action module ---> async_demo 2024-03-11 14:17:22,950 [MainThread ] [INFO ] ACTION REGISTERED ---> AsyncDemo 2024-03-11 14:17:22,950 [MainThread ] [INFO ] Action "AsyncDemo" registered successfully! 2024-03-11 14:17:22,950 [MainThread ] [INFO ] Registering event ---> WebhookReceived 2024-03-11 14:17:22,951 [MainThread ] [DEBUG] Imported event module ---> webhook_received 2024-03-11 14:17:22,951 [MainThread ] [INFO ] Event "WebhookReceived" registered successfully! 2024-03-11 14:17:22,951 [MainThread ] [INFO ] Link "PrintData -> WebhookReceived" registered successfully! 2024-03-11 14:17:22,951 [MainThread ] [INFO ] Link "AsyncDemo -> WebhookReceived" registered successfully! [2024-03-11 14:17:56 +0000] [7] [CRITICAL] WORKER TIMEOUT (pid:8) [2024-03-11 14:17:56 +0000] [8] [INFO] Worker exiting (pid: 8) [2024-03-11 14:17:56 +0000] [9] [INFO] Booting worker with pid: 9 2024-03-11 14:17:57,164 [MainThread ] [INFO ] Registering action ---> PrintData 2024-03-11 14:17:57,165 [MainThread ] [DEBUG] Imported action module ---> print_data 2024-03-11 14:17:57,165 [MainThread ] [INFO ] ACTION REGISTERED ---> PrintData 2024-03-11 14:17:57,165 [MainThread ] [INFO ] Action "PrintData" registered successfully! 2024-03-11 14:17:57,165 [MainThread ] [INFO ] Registering action ---> AsyncDemo 2024-03-11 14:17:57,166 [MainThread ] [DEBUG] Imported action module ---> async_demo 2024-03-11 14:17:57,166 [MainThread ] [INFO ] ACTION REGISTERED ---> AsyncDemo 2024-03-11 14:17:57,166 [MainThread ] [INFO ] Action "AsyncDemo" registered successfully! 2024-03-11 14:17:57,166 [MainThread ] [INFO ] Registering event ---> WebhookReceived 2024-03-11 14:17:57,167 [MainThread ] [DEBUG] Imported event module ---> webhook_received 2024-03-11 14:17:57,167 [MainThread ] [INFO ] Event "WebhookReceived" registered successfully! 2024-03-11 14:17:57,167 [MainThread ] [INFO ] Link "PrintData -> WebhookReceived" registered successfully! 2024-03-11 14:17:57,167 [MainThread ] [INFO ] Link "AsyncDemo -> WebhookReceived" registered successfully!

bashor4life avatar Mar 11 '24 14:03 bashor4life