search

rsalmei / clearly

Clearly see and debug your celery cluster in real time!
MIT License
403 stars 21 forks source link

Unable to see tasks with clearly client #54

Closed stevetho-wpa closed 4 years ago

stevetho-wpa commented 4 years ago

Hello - I have been trying out the docker version of clearly with our instance of celery, backed by rabbitmq. I made the recommended change to the worker invocation to enable events. The server starts up with the following output

2020-04-13 14:54:17,376 clearly.event_core.event_listener INFO Creating EventListener: max_tasks=10000; max_workers=100 Celery broker=amqp://production:**@169.254.255.254:5672; backend=None; using_result_backend=False 2020-04-13 14:54:17,378 clearly.event_core.event_listener INFO Starting listener: <Thread(clearly-listener, started daemon 140432189708032)> 2020-04-13 14:54:17,415 clearly.event_core.streaming_dispatcher INFO Creating StreamingDispatcher 2020-04-13 14:54:17,418 clearly.event_core.streaming_dispatcher INFO Starting dispatcher: <Thread(clearly-dispatcher, started daemon 140432180209408)> 2020-04-13 14:54:17,419 clearly.server INFO Creating ClearlyServer 2020-04-13 14:54:17,419 clearly.server INFO Initiating gRPC server: port=12223 2020-04-13 14:54:17,428 clearly.server INFO gRPC server ok

After I start the client, I can query the workers and the output seems legit

In [3]: clearlycli.workers() celery@10-65-70-179-useast1aprod 6 sw: Linux py-celery 3.1.20 load: [1.34, 1.22, 1.25] processed: 84998 fetched: 1 in 974.91us (1025.73/s)

However, when I try to just clearlycli.capture() it seems to hang and never provides any output. When I try to query tasks already captured by the server, I don't get anything, even though I can check our application logs and see new output and new results of processing:

In [4]: clearlycli.tasks() fetched: 0 in 431.52us (-)

Also the server output doesn't indicate any connection by the client, which seems strange to me, but maybe that's normal.

I'd be grateful for any advice you have. Clearly looks like it could be helpful.

Best regards,

Steve

rsalmei commented 4 years ago

Hello @stevetho-wpa, let's try to understand that, I'm gonna help you.

Well, the server only outputs client connections in debug mode, so please enable that: --debug.

I see that you are using a very very old version of celery, 3.1.20, which I have never tested with. Only with the 3.1.26.post2, the lastest release of 3.1 series.

I can try that here to see if I can figure it out too, but I think the only way to not receive any real time captures would be crashing one of the server threads, which would surely output in the logs.

Please could you send me the log of the server in debug mode, right after calling capture?

rsalmei commented 4 years ago

Oh, one more thing, please use the latest Clearly available, you are probably using some from 0.8, but the 0.9 is already available, and is way more resilient and professional.

rsalmei commented 4 years ago

I've edited your text to remove the password of your production server. Also have deleted that version from here, it is not accessible anymore. The new clearly 0.9 does not print passwords on logs...

rsalmei commented 4 years ago

Just tested it with celery 3.1.20, and it works like a charm.

image
stevetho-wpa commented 4 years ago

'Just seeing this. Thank you very much for your feedback. I will follow up today and get back to you.

stevetho-wpa commented 4 years ago

Thanks again for your help. I updated the clearly docker image (latest: 4 days ago) and added the --debug flag as recommended to the server command line.

Here is the server output, upon calling clearlycli.capture():

2020-04-14 15:43:14,013 clearly.command_line INFO
        __                __
  _____/ /__  ____ ______/ /_  __
 / ___/ / _ \/ __ `/ ___/ / / / / ___ ___ _____  _____ ____
/ /__/ /  __/ /_/ / /  / / /_/ / (_-</ -_) __/ |/ / -_) __/
\___/_/\___/\__,_/_/  /_/\__, /  \__/\__/_/  |___/\__/_/
     version 0.9.1      /____/

2020-04-14 15:43:14,266 clearly.server.server INFO Creating memory: max_tasks=10000; max_workers=100
2020-04-14 15:43:14,267 clearly.server.event_listener INFO Creating EventListener
2020-04-14 15:43:14,275 clearly.server.event_listener INFO broker : amqp://production:**@169.254.255.254:5672//
2020-04-14 15:43:14,284 clearly.server.event_listener INFO backend: disabled://
2020-04-14 15:43:14,284 clearly.server.event_listener INFO Starting: <Thread(clearly-listener, started daemon 140597808195328)>
2020-04-14 15:43:14,304 clearly.server.streaming_dispatcher INFO Creating StreamingDispatcher
2020-04-14 15:43:14,304 clearly.server.streaming_dispatcher INFO Starting: <Thread(clearly-dispatcher-tasks, started daemon 140597798696704)>
2020-04-14 15:43:14,304 clearly.server.streaming_dispatcher INFO Creating StreamingDispatcher
2020-04-14 15:43:14,330 clearly.server.streaming_dispatcher INFO Starting: <Thread(clearly-dispatcher-workers, started daemon 140597790304000)>
2020-04-14 15:43:14,330 clearly.server.server INFO Creating RPCService
2020-04-14 15:43:14,331 clearly.server.server INFO Initiating gRPC server: port=12223
2020-04-14 15:43:14,338 clearly.server.server INFO gRPC server ok
2020-04-14 15:45:23,254 clearly.server.server DEBUG [ipv4:169.254.0.2:47624] CaptureRequest { tasks_capture { pattern: "." } workers_capture { pattern: "." } }

Client is also showing new output:

Ignoring env var: CLI_DISPLAY_MODES=?
        __                __
  _____/ /__  ____ ______/ /_  __      ___          __
 / ___/ / _ \/ __ `/ ___/ / / / / ____/ (_)__ ___  / /_
/ /__/ /  __/ /_/ / /  / / /_/ / / __/ / / -_) _ \/ __/
\___/_/\___/\__,_/_/  /_/\__, /  \__/_/_/\__/_//_/\__/
     version 0.9.1      /____/

Clearly client is ready to use: clearlycli
In [1]: clearlycli.capture()
15:45:23.722 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:25.725 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:27.726 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:29.729 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:31.731 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:33.734 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:35.738 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:37.743 HEARTBEAT celery@10-65-70-179-useast1aprod 6
15:45:39.745 HEARTBEAT celery@10-65-70-179-useast1aprod 6
...

and then...I just had to wait for our logs to show some movement. Apparently that was enough! 

...
16:59:11.469 HEARTBEAT celery@10-65-70-179-useast1aprod 6
16:59:13.471 HEARTBEAT celery@10-65-70-179-useast1aprod 6
16:59:13.550    RETRY 0  922d0f60-5074-480a-9479-3af4130f7e7d
16:59:13.561  STARTED 0  80696113-1f7d-44a1-a033-46d7154741ec
16:59:13.565  STARTED 0  d6f08af1-4dee-4524-bc8e-2ff0e988917c
16:59:13.569 RECEIVED 0 etl.pyscrape.tasks.scrape 6548bff1-f320-4661-b1c4-a23b56559897
16:59:13.572 RECEIVED 0 etl.pyscrape.tasks.scrape 3d490a55-028c-406b-83df-f570dcb56323
16:59:13.648  SUCCESS 0  d6f08af1-4dee-4524-bc8e-2ff0e988917c
16:59:13.651  STARTED 0  283b41af-b3a5-4650-b1f6-998278284a0e
16:59:13.654 RECEIVED 0 etl.pyfiles3.tasks.upload 5d29bfd2-1c16-4856-99e3-44c478e371f1
16:59:13.662  SUCCESS 0  80696113-1f7d-44a1-a033-46d7154741ec
16:59:13.670  STARTED 0  c067666b-cb2b-4602-a07b-18c837e9c314
16:59:13.673 RECEIVED 0 etl.pyfiles3.tasks.upload 56b08c2c-1cb6-4240-a877-5ccb5784c3a3
16:59:13.691  SUCCESS 0  283b41af-b3a5-4650-b1f6-998278284a0e
16:59:13.694  STARTED 0  348eeb0e-504a-40a0-af36-e0b37c93c558
16:59:13.696 RECEIVED 0 etl.pyfiles3.tasks.upload a9534faa-17a8-46ec-ba54-1add6caf3398
16:59:13.739  SUCCESS 0  348eeb0e-504a-40a0-af36-e0b37c93c558
16:59:13.743  STARTED 0  bcb43637-d557-43b2-ac4e-b9ea8c8a1507
16:59:13.746 RECEIVED 0 etl.pyfiles3.tasks.upload 38f80266-8007-4c55-b1fc-90e28c830931
16:59:13.989  SUCCESS 0  bcb43637-d557-43b2-ac4e-b9ea8c8a1507
16:59:13.992  STARTED 0  447e6efd-2a41-443d-9f8a-9031466ca4e1
16:59:13.996 RECEIVED 0 etl.pyfiles3.tasks.upload b137a95c-ceae-45aa-9209-e5b2a33134e0
16:59:14.162  SUCCESS 0  447e6efd-2a41-443d-9f8a-9031466ca4e1
rsalmei commented 4 years ago

Nice! Glad it worked! It is curious the task name is not showing up in states other than RECEIVED, it should, look at the image I've sent. Weird, but it is a success nevertheless.

stevetho-wpa commented 4 years ago

Thanks again. Have a good day, and take care. --Steve

rsalmei commented 4 years ago

You're welcome! 👍