dragonfly
dragonfly copied to clipboard
Published
20 hours ago •
dragonflydb
dragonflydb
oscarsiles/jotlet django app does not work with Dragonfly
I'm trying to test dragonfly on a Django + Channels project, but am getting the following error:
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 4073, in __call__
return client.evalsha(self.sha, len(keys), *args)
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 3143, in evalsha
return self.execute_command('EVALSHA', sha, numkeys, *keys_and_args)
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 901, in execute_command
return self.parse_response(conn, command_name, **options)
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 915, in parse_response
response = connection.read_response()
File "/usr/local/lib/python3.10/site-packages/redis/connection.py", line 756, in read_response
raise response
redis.exceptions.NoScriptError: No matching script. Please use EVAL.
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/asgiref/sync.py", line 472, in thread_handler
raise exc_info[1]
File "/usr/local/lib/python3.10/site-packages/django/core/handlers/exception.py", line 42, in inner
response = await get_response(request)
File "/usr/local/lib/python3.10/site-packages/django/core/handlers/base.py", line 253, in _get_response_async
response = await wrapped_callback(
File "/usr/local/lib/python3.10/site-packages/asgiref/sync.py", line 435, in __call__
ret = await asyncio.wait_for(future, timeout=None)
File "/usr/local/lib/python3.10/asyncio/tasks.py", line 408, in wait_for
return await fut
File "/usr/local/lib/python3.10/site-packages/asgiref/current_thread_executor.py", line 22, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/local/lib/python3.10/site-packages/asgiref/sync.py", line 476, in thread_handler
return func(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/django/views/generic/base.py", line 84, in view
return self.dispatch(request, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/django/views/generic/base.py", line 119, in dispatch
return handler(request, *args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/django/views/generic/edit.py", line 144, in get
return self.render_to_response(self.get_context_data())
File "/workspace/./boards/views.py", line 105, in get_context_data
self.request.session.create()
File "/usr/local/lib/python3.10/site-packages/django/contrib/sessions/backends/db.py", line 54, in create
self.save(must_create=True)
File "/usr/local/lib/python3.10/site-packages/django/contrib/sessions/backends/cached_db.py", line 54, in save
super().save(must_create)
File "/usr/local/lib/python3.10/site-packages/django/contrib/sessions/backends/db.py", line 85, in save
with transaction.atomic(using=using):
File "/usr/local/lib/python3.10/site-packages/cacheops/transaction.py", line 77, in __exit__
self._no_monkey.__exit__(self, exc_type, exc_value, traceback)
File "/usr/local/lib/python3.10/site-packages/cachalot/monkey_patch.py", line 179, in inner
original(self, exc_type, exc_value, traceback)
File "/usr/local/lib/python3.10/site-packages/django/db/transaction.py", line 299, in __exit__
connection.set_autocommit(True)
File "/usr/local/lib/python3.10/site-packages/django/db/backends/base/base.py", line 450, in set_autocommit
self.run_and_clear_commit_hooks()
File "/usr/local/lib/python3.10/site-packages/django/db/backends/base/base.py", line 692, in run_and_clear_commit_hooks
func()
File "/usr/local/lib/python3.10/site-packages/cacheops/transaction.py", line 30, in commit
func(*args, **kwargs)
File "/usr/local/lib/python3.10/site-packages/funcy/decorators.py", line 66, in __call__
return self._func(*self._args, **self._kwargs)
File "/usr/local/lib/python3.10/site-packages/cacheops/invalidation.py", line 32, in invalidate_dict
load_script('invalidate')(keys=[prefix], args=[
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 4079, in __call__
return client.evalsha(self.sha, len(keys), *args)
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 3143, in evalsha
return self.execute_command('EVALSHA', sha, numkeys, *keys_and_args)
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 901, in execute_command
return self.parse_response(conn, command_name, **options)
File "/usr/local/lib/python3.10/site-packages/redis/client.py", line 915, in parse_response
response = connection.read_response()
File "/usr/local/lib/python3.10/site-packages/redis/connection.py", line 756, in read_response
raise response
redis.exceptions.ResponseError: Error running script (call to 7473b25dd38dbe903434e05cfa843a3f40233dfb): @enable_strict_lua:17: user_script:4: Script attempted to access nonexistent global variable 'cjson'
To Reproduce Steps to reproduce the behavior:
- Create Django project with redis cache
- Load a page that uses cache
@oscarsiles Can you please tell what dragonfly version you are running? We had this bug in previous versions but it has been fixed in the latest one.
@romange , you're right, my docker image hadn't updated so force updating fixed that particular issue. However, now when I try to load the page dragonfly reaches 100% CPU and is stuck (blocking the rest of the page from loading).
Running via docker on WSL2, using the following docker-compose settings:
dragonfly:
image: docker.dragonflydb.io/dragonflydb/dragonfly
restart: unless-stopped
command: --cache_mode=true
ulimits:
memlock: -1
ports:
- "6379:6379"
can you please run without docker compose like this
docker run --network=host --ulimit memlock=-1 docker.dragonflydb.io/dragonflydb/dragonfly --vmodule=main_service=2 --logbuflevel=-1 ?
it should create /tmp/dragonfly.INFO file.
after DF will get stuck, can you please kill the process and attach the file here with all the contents?
@oscarsiles your help will be greatly appreciated. If you can not post the log, then maybe the Django code that can reliably reproduce the problem?
@romange apologies, in the middle of meetings! Will post logs once I'm able to later today.
Log below:
I20220627 12:55:27.751170 1 init.cc:56] dragonfly running in opt mode.
I20220627 12:55:27.751236 1 dfly_main.cc:179] maxmemory has not been specified. Deciding myself....
I20220627 12:55:27.751274 1 dfly_main.cc:184] Found 5.91GiB available memory. Setting maxmemory to 4.73GiB
I20220627 12:55:27.752321 9 proactor.cc:456] IORing with 1024 entries, allocated 102720 bytes, cq_entries is 2048
I20220627 12:55:27.754549 1 proactor_pool.cc:66] Running 12 io threads
I20220627 12:55:27.754671 1 main_service.cc:1065] Multi-key commands are:
I20220627 12:55:27.754683 1 main_service.cc:1073] BRPOP: with unlimited keys
I20220627 12:55:27.754698 1 main_service.cc:1073] BLPOP: with unlimited keys
I20220627 12:55:27.754702 1 main_service.cc:1073] DEL: with unlimited keys
I20220627 12:55:27.754709 1 main_service.cc:1073] MSETNX: with unlimited keys
I20220627 12:55:27.754715 1 main_service.cc:1073] ZUNIONSTORE: with 1 keys
I20220627 12:55:27.754745 1 main_service.cc:1073] RENAMENX: with 2 keys
I20220627 12:55:27.754829 1 main_service.cc:1073] UNLINK: with unlimited keys
I20220627 12:55:27.754840 1 main_service.cc:1073] SINTERSTORE: with unlimited keys
I20220627 12:55:27.754844 1 main_service.cc:1073] RPOPLPUSH: with 2 keys
I20220627 12:55:27.754848 1 main_service.cc:1073] SDIFFSTORE: with unlimited keys
I20220627 12:55:27.754853 1 main_service.cc:1073] MGET: with unlimited keys
I20220627 12:55:27.754855 1 main_service.cc:1073] SUNION: with unlimited keys
I20220627 12:55:27.754860 1 main_service.cc:1073] SDIFF: with unlimited keys
I20220627 12:55:27.754863 1 main_service.cc:1073] MSET: with unlimited keys
I20220627 12:55:27.754868 1 main_service.cc:1073] SMOVE: with 2 keys
I20220627 12:55:27.754871 1 main_service.cc:1073] EXISTS: with unlimited keys
I20220627 12:55:27.754874 1 main_service.cc:1073] SUNIONSTORE: with unlimited keys
I20220627 12:55:27.754878 1 main_service.cc:1073] SINTER: with unlimited keys
I20220627 12:55:27.754882 1 main_service.cc:1073] ZINTERSTORE: with 1 keys
I20220627 12:55:27.754886 1 main_service.cc:1073] RENAME: with 2 keys
I20220627 12:55:27.763780 1 server_family.cc:190] Data directory is "/data"
I20220627 12:55:27.763883 1 server_family.cc:114] Checking "/data/dump"
I20220627 12:55:27.763978 11 listener_interface.cc:79] sock[39] AcceptServer - listening on port 6379
I20220627 12:56:23.460845 9 main_service.cc:374] Got: [GET,jotlet:1:django.contrib.sessions.cached_dboh048s4unxgzttmz1qqsgo0md5w479u0]
I20220627 12:56:23.467625 9 main_service.cc:374] Got: [MGET,jotlet:1:a2cec6efb2cb51d9fcdc73ec65d0d02848d3205f,jotlet:1:25dda50c2b14e21edc81e1a84f653586422c612c]
I20220627 12:56:23.581534 9 main_service.cc:374] Got: [MULTI]
I20220627 12:56:23.581647 9 main_service.cc:374] Got: [SET,jotlet:1:a2cec6efb2cb51d9fcdc73ec65d0d02848d3205f,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe5+U.]
I20220627 12:56:23.581746 9 main_service.cc:374] Got: [SET,jotlet:1:25dda50c2b14e21edc81e1a84f653586422c612c,\x80\x04\x95x\x01\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe5+U]\x94]\x94\x8c oh048s4unxgzttmz1qqsgo0md5w479u0\x94\x8c\xe8.eJxVjMsOgjAURP-la0PaXmjFnfwIub2PlEhKImVl_HfBsNDlnJk5LzPiVvO4rfIcJzY348FcfmFCekg5GpznAzdItGylNt_NWa_NfU9S6kRYp6UM5-tPlXHNuwco2hAIEFiBVKAL2EvqlbW1Acn5Tpn56lpFtF2EyOIRNLaJoxNv3h8IlD2T:1o5kq0:dMeOXL-pnCckeiWtzOolPxL_GkYkCxD53bknDx_pnZY\x94\x8c\x08\x64\x61tetime\x94\x8c\x08\x64\x61tetime\x94\x93\x94\x43\n\x07\xe6\x07\x0b\t\x0f\x14\x04\x9a\x18\x94h\x04\x8c\x08timezone\x94\x93\x94h\x04\x8c\ttimedelta\x94\x93\x94K\x00K\x00K\x00\x87\x94R\x94\x85\x94R\x94\x86\x94R\x94\x87\x94\x61\x61\x86\x94.]
I20220627 12:56:23.581773 9 main_service.cc:374] Got: [EXEC]
I20220627 12:56:23.583478 9 main_service.cc:884] Exec unlocking 2 commands
I20220627 12:56:23.583937 9 main_service.cc:890] Exec completed
I20220627 12:56:23.586140 9 main_service.cc:374] Got: [SET,jotlet:1:django.contrib.sessions.cached_dboh048s4unxgzttmz1qqsgo0md5w479u0,\x80\x04\x95\xba\x00\x00\x00\x00\x00\x00\x00}\x94(\x8c\r_auth_user_id\x94\x8c\x02\x32\x33\x94\x8c\x12_auth_user_backend\x94\x8c\x33\x61llauth.account.auth_backends.AuthenticationBackend\x94\x8c\x0f_auth_user_hash\x94\x8c@3c7066c3a3df3cfe356a9eb9fdf406ac125fddd814faa05737de2a3f74bd71e2\x94u.,PX,1196336000]
I20220627 12:56:23.589653 9 main_service.cc:374] Got: [MGET,jotlet:1:2a8af92188b8e48adbd7cb3fadb0bf3e3281067d,jotlet:1:75a4193c8ef5a96909dbe382da7a8c2a3ff0f3c5]
I20220627 12:56:23.597254 9 main_service.cc:374] Got: [MULTI]
I20220627 12:56:23.597329 9 main_service.cc:374] Got: [SET,jotlet:1:2a8af92188b8e48adbd7cb3fadb0bf3e3281067d,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe6\x30\'.]
I20220627 12:56:23.597345 9 main_service.cc:374] Got: [SET,jotlet:1:75a4193c8ef5a96909dbe382da7a8c2a3ff0f3c5,\x80\x04\x95$\x01\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe6\x30\']\x94]\x94(K\x17\x8cXpbkdf2_sha256$320000$99JA4u6oaSHQ8HbB1lbZi9$leINLoL2yEIQCVsyQe7fVyx+rcVAYLkh4H3q7lNsQis=\x94\x8c\x08\x64\x61tetime\x94\x8c\x08\x64\x61tetime\x94\x93\x94\x43\n\x07\xe6\x06\x1b\t\x0f\x14\x03\xca\xe4\x94h\x03\x8c\x08timezone\x94\x93\x94h\x03\x8c\ttimedelta\x94\x93\x94K\x00K\x00K\x00\x87\x94R\x94\x85\x94R\x94\x86\x94R\x94\x89\x8c\x05pczos\x94\x8c\x05Oscar\x94\x8c\x0cSiles Brugge\x94\x8c\"[email protected]\x94\x89\x88h\x05\x43\n\x07\xe6\x02\x11\x12\x0b\x00\x00\x00\x00\x94h\x0e\x86\x94R\x94t\x94\x61\x61\x86\x94.]
I20220627 12:56:23.597369 9 main_service.cc:374] Got: [EXEC]
I20220627 12:56:23.598623 9 main_service.cc:884] Exec unlocking 2 commands
I20220627 12:56:23.599001 9 main_service.cc:890] Exec completed
I20220627 12:56:23.603346 9 main_service.cc:374] Got: [MGET,jotlet:1:1daa4442271ad1c7df05ed273c48808294816a25,jotlet:1:b5ac959681ff06eff632d25a5961a4d3cad09b42,jotlet:1:887f8247d0ff979264c73b069f790024b2aa98e1,jotlet:1:2a8af92188b8e48adbd7cb3fadb0bf3e3281067d,jotlet:1:c13717f65f8d588d217f16740b573e9c961fef16]
I20220627 12:56:23.619177 9 main_service.cc:374] Got: [MULTI]
I20220627 12:56:23.619262 9 main_service.cc:374] Got: [SET,jotlet:1:b5ac959681ff06eff632d25a5961a4d3cad09b42,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe7\x97\xf9.]
I20220627 12:56:23.619282 9 main_service.cc:374] Got: [SET,jotlet:1:1daa4442271ad1c7df05ed273c48808294816a25,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe7\x97\xf9.]
I20220627 12:56:23.619290 9 main_service.cc:374] Got: [SET,jotlet:1:887f8247d0ff979264c73b069f790024b2aa98e1,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe7\x97\xf9.]
I20220627 12:56:23.619300 9 main_service.cc:374] Got: [SET,jotlet:1:c13717f65f8d588d217f16740b573e9c961fef16,\x80\x04\x95\x65\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe7\x97\xf9]\x94]\x94(\x8c\x06\x62oards\x94\x8c\tadd_board\x94\x86\x94\x8c\x06\x62oards\x94\x8c\x0c\x64\x65lete_board\x94\x86\x94\x8c\x06\x62oards\x94\x8c\x13\x63\x61n_view_all_boards\x94\x86\x94\x65\x61\x86\x94.]
I20220627 12:56:23.619311 9 main_service.cc:374] Got: [EXEC]
I20220627 12:56:23.620873 9 main_service.cc:884] Exec unlocking 4 commands
I20220627 12:56:23.621359 9 main_service.cc:890] Exec completed
I20220627 12:56:23.625063 9 main_service.cc:374] Got: [MGET,jotlet:1:f0e3233db5084296e7f4752694dd67e79e2f5d9b,jotlet:1:b5ac959681ff06eff632d25a5961a4d3cad09b42,jotlet:1:542c27005f4e84288827ce70a7d49bc73324a5e7,jotlet:1:887f8247d0ff979264c73b069f790024b2aa98e1,jotlet:1:d59471ff2e371d80132407695b95bf16d25a36cd,jotlet:1:2a8af92188b8e48adbd7cb3fadb0bf3e3281067d,jotlet:1:5fd77033573ec70249680e48674e2b1208f1fabf]
I20220627 12:56:23.644907 9 main_service.cc:374] Got: [MULTI]
I20220627 12:56:23.644958 9 main_service.cc:374] Got: [SET,jotlet:1:542c27005f4e84288827ce70a7d49bc73324a5e7,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe9>N.]
I20220627 12:56:23.644968 9 main_service.cc:374] Got: [SET,jotlet:1:d59471ff2e371d80132407695b95bf16d25a36cd,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe9>N.]
I20220627 12:56:23.644973 9 main_service.cc:374] Got: [SET,jotlet:1:f0e3233db5084296e7f4752694dd67e79e2f5d9b,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe9>N.]
I20220627 12:56:23.644979 9 main_service.cc:374] Got: [SET,jotlet:1:5fd77033573ec70249680e48674e2b1208f1fabf,\x80\x04\x95\x0e\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej=\xe9>N]\x94\x86\x94.]
I20220627 12:56:23.644985 9 main_service.cc:374] Got: [EXEC]
I20220627 12:56:23.646783 9 main_service.cc:884] Exec unlocking 4 commands
I20220627 12:56:23.647295 9 main_service.cc:890] Exec completed
I20220627 12:56:23.648291 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.navbar-button-addBoard.dbffd20747e935da3797c3c26dca38bc]
I20220627 12:56:23.650285 9 main_service.cc:374] Got: [SET,jotlet:1:template.cache.navbar-button-addBoard.dbffd20747e935da3797c3c26dca38bc,\x80\x04\x95\x63\x03\x00\x00\x00\x00\x00\x00\x8c\x17\x64jango.utils.safestring\x94\x8c\nSafeString\x94\x93\x94X/\x03\x00\x00\n <li class=\"nav-item\">\n <span data-bs-toggle=\"collapse\" data-bs-target=\"#navbarText\">\n <a class=\"nav-link\"\n role=\"button\"\n hx-get=\"/boards/create/\"\n hx-target=\"#modal-1-body-div\"\n data-bs-toggle=\"modal\"\n data-bs-target=\"#modal-1-div\">\n Create board\n </a>\n </span>\n </li>\n \x94\x85\x94\x81\x94.,PX,86400000]
I20220627 12:56:23.651448 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.navbar-user-menu.706401b3b6d77716801f1a472817444f]
I20220627 12:56:23.654350 9 main_service.cc:374] Got: [SET,jotlet:1:template.cache.navbar-user-menu.706401b3b6d77716801f1a472817444f,\x80\x04\x95\xa1\x08\x00\x00\x00\x00\x00\x00\x8c\x17\x64jango.utils.safestring\x94\x8c\nSafeString\x94\x93\x94Xm\x08\x00\x00\n <li class=\"nav-item dropdown\">\n <a class=\"nav-link dropdown-toggle\"\n href=\"#\"\n id=\"navbarDropdownMenuLink\"\n role=\"button\"\n data-bs-toggle=\"dropdown\"\n aria-expanded=\"false\">\n pczos\n </a>\n <ul class=\"dropdown-menu dropdown-menu-lg-end\"\n aria-labelledby=\"navbarDropdownMenuLink\">\n \n <li>\n <span data-bs-toggle=\"collapse\" data-bs-target=\"#navbarText\">\n <a class=\"dropdown-item\"\n role=\"button\"\n hx-get=\"/accounts/password/change/?next=/boards/\"\n hx-target=\"#modal-1-body-div\"\n data-bs-toggle=\"modal\"\n data-bs-target=\"#modal-1-div\">\n Change Password\n </a>\n </span>\n </li>\n <li>\n <a class=\"dropdown-item\"\n role=\"button\"\n hx-post=\"/accounts/logout/?next=/boards/\"\n hx-target=\"body\">\n Logout\n </a>\n </li>\n </ul>\n </li>\n \x94\x85\x94\x81\x94.,PX,86400000]
I20220627 12:56:23.752580 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.index-list-title.113deeff2ee608c8b7ea268dd8170173]
I20220627 12:56:23.754426 9 main_service.cc:374] Got: [SET,jotlet:1:template.cache.index-list-title.113deeff2ee608c8b7ea268dd8170173,\x80\x04\x95#\x03\x00\x00\x00\x00\x00\x00\x8c\x17\x64jango.utils.safestring\x94\x8c\nSafeString\x94\x93\x94X\xef\x02\x00\x00\n <div class=\"py-2\">\n <div class=\"d-flex gap-2\">\n <h4>\n \n Your boards (pczos):\n \n </h4>\n <div class=\"spinner-border htmx-indicator\" role=\"status\">\n <span class=\"visually-hidden\">Loading...</span>\n </div>\n </div>\n </div>\n <script id=\"is_all_boards\" type=\"application/json\">\"\"</script>\n <div id=\"board-list\"\n hx-get=\"/boards/list/\"\n hx-trigger=\"load\"\n hx-swap=\"innerHTML\"></div>\n \x94\x85\x94\x81\x94.,PX,3600000]
I20220627 12:56:23.776062 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.toast.d41d8cd98f00b204e9800998ecf8427e]
I20220627 12:56:23.776820 9 main_service.cc:374] Got: [SET,jotlet:1:template.cache.toast.d41d8cd98f00b204e9800998ecf8427e,\x80\x04\x95_\x03\x00\x00\x00\x00\x00\x00\x8c\x17\x64jango.utils.safestring\x94\x8c\nSafeString\x94\x93\x94X+\x03\x00\x00\n<div class=\"position-fixed bottom-0 end-0 p-3\"\n x-data=\"toastNotification()\">\n <div id=\"toast\"\n class=\"toast align-items-center border-0\"\n x-bind:class=\"bg_color\"\n @show-message.camel.window=\"openToast($event); new bootstrap.Toast($el).show();\"\n role=\"alert\"\n data-bs-delay=\"3000\"\n aria-live=\"assertive\"\n aria-atomic=\"true\">\n <div class=\"d-flex\">\n <div id=\"toast-body\" class=\"toast-body\" x-text=\"message\"></div>\n <button id=\"toast-close\"\n type=\"button\"\n class=\"btn-close shadow-none me-2 m-auto\"\n x-bind:class=\"btn_color\"\n data-bs-dismiss=\"toast\"\n aria-label=\"Close\">\n </button>\n </div>\n </div>\n</div>\n\x94\x85\x94\x81\x94.,PX,86400000]
I20220627 12:56:23.792788 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.modal.3afcdbfeb6ecfbdd0ba628696e3cc163]
I20220627 12:56:23.802090 9 main_service.cc:374] Got: [SET,jotlet:1:template.cache.modal.3afcdbfeb6ecfbdd0ba628696e3cc163,\x80\x04\x95\x64\x04\x00\x00\x00\x00\x00\x00\x8c\x17\x64jango.utils.safestring\x94\x8c\nSafeString\x94\x93\x94X0\x04\x00\x00\n<div class=\"modal fade\"\n id=\"modal-1-div\"\n tabindex=\"-1\"\n >\n <div class=\"modal-dialog modal-dialog-scrollable\">\n <div class=\"modal-content\">\n <div class=\"modal-header\">\n <h5 class=\"modal-title\" id=\"modal-1-title-div\">Loading...</h5>\n \n <button type=\"button\"\n class=\"btn-close\"\n data-bs-dismiss=\"modal\"\n aria-label=\"Close\"\n tabindex=\"-1\"></button>\n \n </div>\n <div class=\"modal-body\" id=\"modal-1-body-div\">\n <div class=\"d-flex justify-content-center\">\n <div class=\"spinner-border\" role=\"status\">\n <span class=\"visually-hidden\">Loading...</span>\n </div>\n </div>\n </div>\n <div class=\"modal-footer\" id=\"modal-1-footer-div\" hidden=\"true\"></div>\n <div id=\"modal-1-scripts\" hidden=\"true\"></div>\n </div>\n </div>\n</div>\n\x94\x85\x94\x81\x94.,PX,86400000]
I20220627 12:56:23.818305 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.modal.247730f9d0d2eaad265a470e32aa0cdf]
I20220627 12:56:23.819496 9 main_service.cc:374] Got: [SET,jotlet:1:template.cache.modal.247730f9d0d2eaad265a470e32aa0cdf,\x80\x04\x95\xee\x04\x00\x00\x00\x00\x00\x00\x8c\x17\x64jango.utils.safestring\x94\x8c\nSafeString\x94\x93\x94X\xba\x04\x00\x00\n<div class=\"modal fade\"\n id=\"modal-2-div\"\n tabindex=\"-1\"\n data-bs-backdrop=\"static\" data-bs-keyboard=\"false\">\n <div class=\"modal-dialog modal-dialog-scrollable modal-xl\">\n <div class=\"modal-content\">\n <div class=\"modal-header\">\n <h5 class=\"modal-title\" id=\"modal-2-title-div\">Loading...</h5>\n \n <button type=\"button\"\n class=\"btn-close\"\n data-bs-toggle=\"modal\"\n data-bs-target=\"#modal-1-div\"\n aria-label=\"Close\"\n tabindex=\"-1\">\n </button>\n \n </div>\n <div class=\"modal-body\" id=\"modal-2-body-div\">\n <div class=\"d-flex justify-content-center\">\n <div class=\"spinner-border\" role=\"status\">\n <span class=\"visually-hidden\">Loading...</span>\n </div>\n </div>\n </div>\n <div class=\"modal-footer\" id=\"modal-2-footer-div\" hidden=\"true\"></div>\n <div id=\"modal-2-scripts\" hidden=\"true\"></div>\n </div>\n </div>\n</div>\n\x94\x85\x94\x81\x94.,PX,86400000]
I20220627 12:56:23.820813 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.base-script-modals.d41d8cd98f00b204e9800998ecf8427e]
I20220627 12:56:23.834867 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.modal.3afcdbfeb6ecfbdd0ba628696e3cc163]
I20220627 12:56:23.849239 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.modal.247730f9d0d2eaad265a470e32aa0cdf]
I20220627 12:56:23.850423 9 main_service.cc:374] Got: [SET,jotlet:1:template.cache.base-script-modals.d41d8cd98f00b204e9800998ecf8427e,\x80\x04\x95\xaf\x0b\x00\x00\x00\x00\x00\x00\x8c\x17\x64jango.utils.safestring\x94\x8c\nSafeString\x94\x93\x94X{\x0b\x00\x00\n htmx.on(\"hidden.bs.modal\", function (e) {\n var modal2 = bootstrap.Modal.getInstance(\n document.getElementById(\"modal-2-div\")\n );\n var modal2_isShown = false;\n try {\n modal2_isShown = modal2._isShown;\n } catch (err) {}\n \n if (!modal2_isShown && e.target.id == \"modal-1-div\") {\n htmx.find(\n \"#modal-1-div\"\n ).outerHTML = `\n\n<div class=\"modal fade\"\n id=\"modal-1-div\"\n tabindex=\"-1\"\n >\n <div class=\"modal-dialog modal-dialog-scrollable\">\n <div class=\"modal-content\">\n <div class=\"modal-header\">\n <h5 class=\"modal-title\" id=\"modal-1-title-div\">Loading...</h5>\n \n <button type=\"button\"\n class=\"btn-close\"\n data-bs-dismiss=\"modal\"\n aria-label=\"Close\"\n tabindex=\"-1\"></button>\n \n </div>\n <div class=\"modal-body\" id=\"modal-1-body-div\">\n <div class=\"d-flex justify-content-center\">\n <div class=\"spinner-border\" role=\"status\">\n <span class=\"visually-hidden\">Loading...</span>\n </div>\n </div>\n </div>\n <div class=\"modal-footer\" id=\"modal-1-footer-div\" hidden=\"true\"></div>\n <div id=\"modal-1-scripts\" hidden=\"true\"></div>\n </div>\n </div>\n</div>\n\n`;\n }\n \n if (e.target.id == \"modal-2-div\") {\n htmx.find(\n \"#modal-2-div\"\n ).outerHTML = `\n\n<div class=\"modal fade\"\n id=\"modal-2-div\"\n tabindex=\"-1\"\n data-bs-backdrop=\"static\" data-bs-keyboard=\"false\">\n <div class=\"modal-dialog modal-dialog-scrollable modal-xl\">\n <div class=\"modal-content\">\n <div class=\"modal-header\">\n <h5 class=\"modal-title\" id=\"modal-2-title-div\">Loading...</h5>\n \n <button type=\"button\"\n class=\"btn-close\"\n data-bs-toggle=\"modal\"\n data-bs-target=\"#modal-1-div\"\n aria-label=\"Close\"\n tabindex=\"-1\">\n </button>\n \n </div>\n <div class=\"modal-body\" id=\"modal-2-body-div\">\n <div class=\"d-flex justify-content-center\">\n <div class=\"spinner-border\" role=\"status\">\n <span class=\"visually-hidden\">Loading...</span>\n </div>\n </div>\n </div>\n <div class=\"modal-footer\" id=\"modal-2-footer-div\" hidden=\"true\"></div>\n <div id=\"modal-2-scripts\" hidden=\"true\"></div>\n </div>\n </div>\n</div>\n\n`;\n }\n });\n \x94\x85\x94\x81\x94.,PX,86400000]
I20220627 12:56:24.147714 9 main_service.cc:374] Got: [GET,jotlet:1:django.contrib.sessions.cached_dboh048s4unxgzttmz1qqsgo0md5w479u0]
I20220627 12:56:24.151628 9 main_service.cc:374] Got: [MGET,jotlet:1:2a8af92188b8e48adbd7cb3fadb0bf3e3281067d,jotlet:1:75a4193c8ef5a96909dbe382da7a8c2a3ff0f3c5]
I20220627 12:56:24.182469 9 main_service.cc:374] Got: [MGET,jotlet:1:e6d20a7e7dc5182b2ed05c627f7880ec3242baf0,jotlet:1:2a8af92188b8e48adbd7cb3fadb0bf3e3281067d,jotlet:1:2b2e1135d9c45b1e0dc8a968af08a5ff5e333c85]
I20220627 12:56:24.354130 9 main_service.cc:374] Got: [MULTI]
I20220627 12:56:24.354234 9 main_service.cc:374] Got: [SET,jotlet:1:e6d20a7e7dc5182b2ed05c627f7880ec3242baf0,\x80\x04\x95\n\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej>\x16\xa0%.]
I20220627 12:56:24.354255 9 main_service.cc:374] Got: [SET,jotlet:1:2b2e1135d9c45b1e0dc8a968af08a5ff5e333c85,\x80\x04\x95\x10\x00\x00\x00\x00\x00\x00\x00GA\xd8\xaej>\x16\xa0%K\x01\x85\x94\x86\x94.]
I20220627 12:56:24.354266 9 main_service.cc:374] Got: [EXEC]
I20220627 12:56:24.355707 9 main_service.cc:884] Exec unlocking 2 commands
I20220627 12:56:24.356283 9 main_service.cc:890] Exec completed
I20220627 12:56:24.531312 9 main_service.cc:374] Got: [MGET,jotlet:1:e6d20a7e7dc5182b2ed05c627f7880ec3242baf0,jotlet:1:2a8af92188b8e48adbd7cb3fadb0bf3e3281067d,jotlet:1:d5f10e85a25ecabce27b8f7a727ef26d624c5563]
I20220627 12:56:24.543025 9 main_service.cc:374] Got: [MULTI]
I20220627 12:56:24.543131 9 main_service.cc:374] Got: [SET,jotlet:1:d5f10e85a25ecabce27b8f7a727ef26d624c5563,\x80\x04\x95\x8a\x01\x00\x00\x00\x00\x00\x00GA\xd8\xaej>\"\xb5\xcc]\x94]\x94(K\x18\x8c\nother user\x94\x8c\x16nc9iQ9SFcVGzBe2UntrVNh\x94\x8c\x06\x39\x35\x30\x31\x39\x35\x94\x8c\x06sdfsfs\x94K\x17\x8c\x08\x64\x61tetime\x94\x8c\x08\x64\x61tetime\x94\x93\x94\x43\n\x07\xe6\x02\x17\x0e\n.\x04\xf9p\x94h\x06\x8c\x08timezone\x94\x93\x94h\x06\x8c\ttimedelta\x94\x93\x94K\x00K\x00K\x00\x87\x94R\x94\x85\x94R\x94\x86\x94R\x94h\x08\x43\n\x07\xe6\x03\t\x15\x12\x03\x01\r\x88\x94h\x11\x86\x94R\x94K\x17\x8cXpbkdf2_sha256$320000$99JA4u6oaSHQ8HbB1lbZi9$leINLoL2yEIQCVsyQe7fVyx+rcVAYLkh4H3q7lNsQis=\x94h\x08\x43\n\x07\xe6\x06\x1b\t\x0f\x14\x03\xca\xe4\x94h\x11\x86\x94R\x94\x89\x8c\x05pczos\x94\x8c\x05Oscar\x94\x8c\x0cSiles Brugge\x94\x8c\"[email protected]\x94\x89\x88h\x08\x43\n\x07\xe6\x02\x11\x12\x0b\x00\x00\x00\x00\x94h\x11\x86\x94R\x94t\x94\x61\x61\x86\x94.]
I20220627 12:56:24.543241 9 main_service.cc:374] Got: [EXEC]
I20220627 12:56:24.544430 9 main_service.cc:884] Exec unlocking 1 commands
I20220627 12:56:24.544912 9 main_service.cc:890] Exec completed
I20220627 12:56:24.548811 9 main_service.cc:374] Got: [GET,jotlet:1:template.cache.board-list-post-count.061c16448aee6be07e20ab574ef27ea4]
I20220627 12:56:24.561594 10 main_service.cc:374] Got: [SELECT,1]
I20220627 12:56:24.562620 10 main_service.cc:374] Got: [GET,as:cbbd47d8465f0a6569c00f0a2d1870fe]
I20220627 12:56:24.576606 10 main_service.cc:374] Got: [EVALSHA,48f6ff98e648e4e33abd0de6769a9673304154b1,3,,as:cbbd47d8465f0a6569c00f0a2d1870fe,,\x80\x04K\x02.,{\"boards_post\": [{}], \"boards_topic\": [{\"board_id\": 24}]},3600]
I20220627 12:56:24.577335 10 main_service.cc:374] Got: [SCRIPT,LOAD,local prefix = KEYS[1]\nlocal key = KEYS[2]\nlocal precall_key = KEYS[3]\nlocal data = ARGV[1]\nlocal dnfs = cjson.decode(ARGV[2])\nlocal timeout = tonumber(ARGV[3])\n\nif precall_key ~= prefix and redis.call(\'exists\', precall_key) == 0 then\n -- Cached data was invalidated during the function call. The data is\n -- stale and should not be cached.\n return\nend\n\n-- Write data to cache\nredis.call(\'setex\', key, timeout, data)\n\n\n-- A pair of funcs\n-- NOTE: we depend here on keys order being stable\nlocal conj_schema = function (conj)\n local parts = {}\n for field, _ in pairs(conj) do\n table.insert(parts, field)\n end\n\n return table.concat(parts, \',\')\nend\n\nlocal conj_cache_key = function (db_table, conj)\n local parts = {}\n for field, val in pairs(conj) do\n table.insert(parts, field .. \'=\' .. tostring(val))\n end\n\n return prefix .. \'conj:\' .. db_table .. \':\' .. table.concat(parts, \'&\')\nend\n\n\n-- Update schemes and invalidators\nfor db_table, disj in pairs(dnfs) do\n for _, conj in ipairs(disj) do\n -- Ensure scheme is known\n redis.call(\'sadd\', prefix .. \'schemes:\' .. db_table, conj_schema(conj))\n\n -- Add new cache_key to list of dependencies\n local conj_key = conj_cache_key(db_table, conj)\n redis.call(\'sadd\', conj_key, key)\n -- NOTE: an invalidator should live longer than any key it references.\n -- So we update its ttl on every key if needed.\n -- NOTE: if CACHEOPS_LRU is True when invalidators should be left persistent,\n -- so we strip next section from this script.\n -- TOSTRIP\n local conj_ttl = redis.call(\'ttl\', conj_key)\n if conj_ttl < timeout then\n -- We set conj_key life with a margin over key life to call expire rarer\n -- And add few extra seconds to be extra safe\n redis.call(\'expire\', conj_key, timeout * 2 + 10)\n end\n -- /TOSTRIP\n end\nend\n]
I20220627 12:56:24.578122 10 main_service.cc:374] Got: [EVALSHA,d23dd0027a4d96f365efef3aeb21ce6c5bf07976,3,,as:cbbd47d8465f0a6569c00f0a2d1870fe,,\x80\x04K\x02.,{\"boards_post\": [{}], \"boards_topic\": [{\"board_id\": 24}]},3600]
Based on that, I'm assuming it's getting stuck processing a cache invalidation from this package: https://github.com/Suor/django-cacheops .
Can I assume that running https://github.com/oscarsiles/jotlet integrated with dragonfly triggers this bug @oscarsiles ?
@oscarsiles how do I start you django app? I've installed your requirements-dev.txt but not sure how to run it from the repo 🤔
Yes, it's on my (long) to-do list to write it up... assuming you have postgres (with environment variables DB_USER, DB_PASSWORD, DB_HOST configured) and redis/dragonfly running you should be able to run the following commands:
python manage.py migratepython manage.py collectstatic --noinputuvicorn jotlet.asgi:application --host 0.0.0.0 --reload
Hopefully that's minimal enough to run without needing a superuser...
For the protocol, to be able to run the app, I run posgresql like this:
docker run --name some-postgres -e POSTGRES_PASSWORD=pass --rm -v /var/run/postgresql:/var/run/postgresql postgres
and then exported variables like:
export DB_NAME=postgres
export DB_PASSWORD=pass
export DB_USER=postgres
then the command python manage.py migrate failed with error
redis.exceptions.ResponseError: Error running script (call to 0605214935a9ffcd4b9e5779300302540ff08da4): @enable_strict_lua:17: user_script:4: Script attempted to access nonexistent global variable 'cjson'
This is expected, because currently our lua support does not include third party libraries like cjson.
Unfortunately, I did not succeed to reproduce the case where dragonfly is being stuck on 100% cpu.
@romange I used this excellent visual guide to try to reproduce the problem and I didn't have any problems. Everything worked just fine!
I used: Manjaro Linux 21.3.7 dragonfly:latest Python 3.10.5 django 4.1.1 redis 4.3.4 hiredis 2.0.0 (I didn't use the django-redis library) Also, through the RESP.app (nice GUI for Redis) I was watching the entries in the database to make sure they appeared there.
@oscarsiles You wrote that you are using django channels library - maybe the problem is with it. Are you using Dragonfly as the backing store for the channel layer?
@alexted - look at #184 - we confirmed that this library does not work with DF yet.
- It requires cjson lua support (fixed in v0.7)
- It uses relaxed Lua scripts that access run-time generated, undeclated keys (DF does not support it today).
Should work if dragonfly is running with flags: --default_lua_config="allow-undeclared-keys disable-atomicity" or --default_lua_config="allow-undeclared-keys". The latter runs Dragonfly with eval call under a global lock (not recommended due to its low performance ). The former runs lua scripts non-atomically. Lua atomicity seems to be not needed for this use-case anyway.