bazaar icon indicating copy to clipboard operation
bazaar copied to clipboard

Redis having 100 changes in 300 seconds even when idle

Open anantshri opened this issue 2 years ago • 0 comments

TL:DR; our taskmanager hits redis every 0.2 seconds to check for pending tasks we can reduce it by adding a parameter in config/settings/base.py

diff --git a/config/settings/base.py b/config/settings/base.py
index b66483a..c35a9b1 100644
--- a/config/settings/base.py
+++ b/config/settings/base.py
@@ -349,6 +349,7 @@ Q_CLUSTER = {
     'retry': 20*60,
     'recycle': 1,
     'max_attempts': 5,
+    "guard_cycle": 10,
     'timeout': 19*60,
     'compress': True,
     'save_limit': 25,

Long Details

I keep getting these messages after regular interval even when nothing is happening on application.

redis_1          | 2022-12-29T11:13:04.096568776Z 1:M 29 Dec 2022 11:13:04.096 * 100 changes in 300 seconds. Saving...
redis_1          | 2022-12-29T11:13:04.097868021Z 1:M 29 Dec 2022 11:13:04.097 * Background saving started by pid 280
redis_1          | 2022-12-29T11:13:04.101346575Z 280:C 29 Dec 2022 11:13:04.101 * DB saved on disk
redis_1          | 2022-12-29T11:13:04.103382853Z 280:C 29 Dec 2022 11:13:04.103 * RDB: 0 MB of memory used by copy-on-write
redis_1          | 2022-12-29T11:13:04.198490918Z 1:M 29 Dec 2022 11:13:04.198 * Background saving terminated with success

This led me to check what is being written on redis using redis-cli monitor on running redis instance using

docker exec -it <instanceID> redis-cli monitor

I was able to identify these messages

1672315334.573630 [0 172.19.0.10:47526] "BLPOP" "django_q:Backend:q" "1"
1672315334.706288 [0 172.19.0.10:47516] "SET" "django_q:Backend:cluster:175a55d3-174a-424f-ad30-c830f40d3c92" ".eJxVUM0uQ0EURkurSkUkJfETu9o0RWJlhQ2zkKAbidzM7R06ejtzO3MmtImEBQs5K47H8BJW9jyDHSsPYG5FwmzOmZx8v1fDj2-DA_2HpeiMq1MddKoWODhLmD3wCz3Q8jVdUgVz59q0hLF0TBXWYm2mWUdgBnRImI84CJBt8Xd9oK1C7r04Nz5Vy39-eL6kCz0_gvrhVkq7T7e0TzhhhFQNbhQHqZUltoSZREbERrHQiJ0FYQL_xaxz_VGv72z_usKMVEB3k_cb41-1l9rT3uZu-bV-VLYh5q1QIJWIic3iyG-m8k_KqgMZ2-qJU41UlMeE00HMe90gMfqiGziVyEYrTjNUcOYfBgxXNu57JcydCgBxkbaE2Z3IA25SV_nQydiLe8GMBeOvkCYdi7QSQSewsieIDWC2qS0QFqOVcDVcj8K1tWjVc7a1kqANsQUcA25bfxAjibNN4U-LOJp27GO1E2oW-kXPF4cmCs_X1Cylvbqw-g3-Vrqj:1pArby:xWboTt4qIlG0yFTrU4lPvcNy2TTg1jA48mT1EUx2SP8" "EX" "3"
1672315335.208665 [0 172.19.0.10:47516] "SET" "django_q:Backend:cluster:175a55d3-174a-424f-ad30-c830f40d3c92" ".eJxVUD9LI0EUVzeaGKORQ8gJnmKXswgxgtVVaqNTCGoaQZbZ7JwZs5nZzLxBExC00EJepc-PcR9DsNfPYKeVH8DZHIJO897w-P29GL9_Hh0ZPizHJ1wd67BXs8DBWcLcvl_ojn5f0jlVMX-qTUcYS0dUZR3WZZr1BAagI8JCzEGA7Iqv6x1tFvMvpYXpH_XC26vnS_sw8CNsHmxmtHt0TXuEM0ZI1eJGcZBaWWLLGKQyJjaJxVbiLAgT-i_mnBuOZnN769MVBlIB3cze_pl-rz_W_-1u7FSemocVG2HBCgVSiYTYPE58Zqr8T1lzIBNb--tUKxPlCeFcmPBBP0yNPuuHTqWy1UmyDFX8-Q0DhiubDL0S5o8FgDjLWsLcduwBV5mrQuRk4sW9YGDB-CtkSadirUTYC60cCGIjmGtrC4SleDVqROtxtLYWNzxnVysJ2hBbxCngtvMFMZE62xb-tISTWcc-VjeldnFY9K_SWDlYeaB2OevVRbUP-dW6SQ:1pArbz:WNNY_Cz4s_66HXtqBZx8S2C3WV_Td5z_7smLNWmBZkw" "EX" "3"

These messages point to django-q as the culprit, looking at the closed issues on the repository found https://github.com/Koed00/django-q/issues/359 matching my scenarios and that points to a bug https://github.com/paperless-ngx/paperless-ngx/issues/1084 which points to https://github.com/paperless-ngx/paperless-ngx/issues/1084#issuecomment-1145752785 comment and confirms suspicion. There is an associated pull request : https://github.com/paperless-ngx/paperless-ngx/pull/1091/files and Documentation https://django-q.readthedocs.io/en/latest/configure.html#guard-cycle

https://github.com/Pithus/bazaar/blob/master/config/settings/base.py#L346 This is our config file

I have reduced this to 5 seconds and I see a slightly lower cpu usage but I want someone else to test this and confirm if this is the case.

anantshri avatar Dec 29 '22 14:12 anantshri