Dragonfly crash in k8s

[Smolsada]

Sometimes I see a dragonfly crash for no apparent reason. Is it something well known?

dragonfly chart version: v1.4.0

In logs:

PC: @     0x563beaffca6b  (unknown)  util::fb2::intrusive_ptr_release()
*** SIGSEGV received at time=1687353302 on cpu 1 ***

[royjacobson]

We've seen some related crashes recently and are working on a fix, but it's hard to be sure if they're the same ones from this error alone... Do you happen to use blocking commands? (BLPOP and others)

[Smolsada]

So far, i'm only using dragonfly for redlock. I didn't go into the implementation, but i'm almost sure that lua script and setnx are used under the hood.

[adiholden]

Hi @Letfdsada ,
I believe that we did not see this specific crash before.
What is the machine you are running on? are you running on x86 or Arm? which library you are using for redlock?
Any additional information that can help us to reproduce your crash will be helpful

[romange]

@Letfdsada Thank you! you mentioned logging. It would help us if you could record the commands by adding --vmodule=main_service=2 to dragonfly command-line arguments.
The commands will be stored inside dragonfly.INFO log or in stderr depending on your pod configuration. The log file contains
line Starting dragonfly df-1.4.0 in the beginning.
It could help us if you could run dragonfly for a few hours and aggregate commands in the log file and share the log with us.
Then we could try and replay it locally in the hope we will be able to reproduce the failure.

[adiholden]

@Letfdsada
Can you please run SCRIPT LIST on the instance and paste here the output?
Are there more logs from the crash ? can you add them as well?
Another request , could you run dragonfly with flag multi_exec_squash=false , and see if you still experience the crash. We have entered some optimisation lately for scripts and I want to understand if the problem is coming from this flow.

[Smolsada]

@adiholden

Can you please run SCRIPT LIST on the instance and paste here the output?

root@dragonfly-stable-654fb7d9cc-mclz2:/data# redis-cli
127.0.0.1:6379> SCRIPT LIST
1) 1) "6294299faa74c6d411ac7d0da9416eef4a07d268"
   2) "if redis.call('get', ARGV[1]) == ARGV[2] then return redis.call('pexpire', ARGV[1], ARGV[3]) end return 0"
2) 1) "d0dada9c1dfc9ec23dd124919a35b6e72da5a780"
   2) "if redis.call('get', ARGV[1]) == ARGV[2] then return redis.call('del', ARGV[1]) end return 0"

Are there more logs from the crash ? can you add them as well?

Full log on instance:

I20230621 13:14:04.724088     1 init.cc:69] dragonfly running in opt mode.
I20230621 13:14:04.724201     1 dfly_main.cc:618] Starting dragonfly df-v1.4.0-6d4d740d6e2a060cbbbecd987ee438cc6e60de79

I20230621 13:14:04.724359     1 dfly_main.cc:671] Max memory limit is: 1000.00MiB
W20230621 13:14:04.724385     1 dfly_main.cc:428] Kernel is older than 5.10, switching to epoll engine.
I20230621 13:14:04.728536     1 proactor_pool.cc:147] Running 2 io threads
I20230621 13:14:04.738384     1 server_family.cc:161] Data directory is "/data"
I20230621 13:14:04.740552     9 listener_interface.cc:96] sock[8] AcceptServer - listening on port 6379
*** SIGSEGV received at time=1687353302 on cpu 1 ***
PC: @     0x563beaffca6b  (unknown)  util::fb2::intrusive_ptr_release()
I20230621 13:15:03.962841     1 init.cc:69] dragonfly running in opt mode.
I20230621 13:15:03.963016     1 dfly_main.cc:618] Starting dragonfly df-v1.4.0-6d4d740d6e2a060cbbbecd987ee438cc6e60de79
I20230621 13:15:03.963204     1 dfly_main.cc:671] Max memory limit is: 1000.00MiB
W20230621 13:15:03.963236     1 dfly_main.cc:428] Kernel is older than 5.10, switching to epoll engine.
I20230621 13:15:03.967216     1 proactor_pool.cc:147] Running 2 io threads
I20230621 13:15:03.977174     1 server_family.cc:161] Data directory is "/data"
I20230621 13:15:03.978936     9 listener_interface.cc:96] sock[8] AcceptServer - listening on port 6379
E20230701 07:13:13.133087     9 epoll_socket.cc:358] sock[17] Unexpected error 110/Connection timed out 0.0.0.0:0
W20230701 07:13:13.133185     9 dragonfly_connection.cc:531] Socket error system:110 Connection timed out

[Smolsada]

@romange
I think i need to set up logging to a file. Because 5000 log lines are written to the terminal per minute. It will be hard to get them all out. I'll try to redirect this week if it needed.

Here is result of the last 5000 rows. I replaced the strings that might be sensitive and did a distinct.

[PING] in dbid=0
[EVALSHA,MySha,1,MyKey] in dbid=0
LUA [GET,MyKey] in dbid=0
LUA [PEXPIRE,MyKey] in dbid=0
[INFO,replication] in dbid=0
[SET,MyKey] in dbid=0

[romange]

The annotated log with the failure stack trace is useful. Please send us more if the failure occurs again

[Smolsada]

I am with some news.
After multi_exec_squash=false and with new versions (we update chart automatically), crashes are eliminated or at least appears less frequently. Haven't seen one in the last 12 days.

[romange]

@dranikpg FYI

[Smolsada]

Surprisingly, i never turned off flag on staging :)
For a month or more, not a single crash happened.
Therefore, it seems that matter is not in the flag.
I'm sorry, it's been a tough week. A little later, i will look at the k8s metrics to understand when the crashes stopped.

[romange]

We fixed quite a few bugs :)

[dranikpg]

multi_exec_squash if now off by default, isn't it? (besides script squashing is not triggered with this flag)

[Smolsada]

I'm sorry for late reply. Stuck at work :(

Unfortunately, I didn’t have a metric that would show restarts due to crashes. Because for old metrics we greatly reduce the accuracy.

So it can be said that something has changed since 1.7 (inclusive, based on the history of this discussion)

[romange]

closing this discussion. if you see any bugs or crashes, please open an issue