search

dragonflydb / dragonfly

A modern replacement for Redis and Memcached
https://www.dragonflydb.io/
Other
25.28k stars 910 forks source link

Server misbehaving on Golang benchmarks #993

Closed YaroslavPodorvanov closed 1 year ago

YaroslavPodorvanov commented 1 year ago

Describe the bug Dragonfly docker container exit on benchmarks

To Reproduce Steps to reproduce the behavior:

  1. Clone repository with benchmarks on Golang

    git clone --branch dragonflydb-server-misbehaving https://github.com/doutivity/research-online-redis-go.git

  2. Up

    docker-compose up -d # or make env-up

  3. See containers and DragonflyDB docker image version

    docker ps
    CONTAINER ID   IMAGE                                         COMMAND                  CREATED          STATUS                    PORTS      NAMES
1b9eb22dabfb   golang:1.20.0-alpine                          "sleep 1d"               21 minutes ago   Up 21 minutes                        research-online-redis-go-app
3e30488a2868   eqalpha/keydb:latest                          "docker-entrypoint.s…"   21 minutes ago   Up 21 minutes             6379/tcp   research-online-keydb-1
929c4c9fb81c   docker.dragonflydb.io/dragonflydb/dragonfly   "entrypoint.sh drago…"   21 minutes ago   Up 10 minutes (healthy)   6379/tcp   research-online-dragonflydb-1
3a41ada90d8a   redis:latest                                  "docker-entrypoint.s…"   21 minutes ago   Up 21 minutes             6379/tcp   research-online-redis-1
    docker image inspect docker.dragonflydb.io/dragonflydb/dragonfly --format '{{.RepoDigests}}'
    [docker.dragonflydb.io/dragonflydb/dragonfly@sha256:a588d8f6924742772253e669dd088b31e17207967563b435401d0a8a9293b09d]

  4. Monitor DragonflyDB container logs in Terminal 1

    docker logs -f research-online-dragonflydb-1
    I20230326 05:15:07.822724     1 init.cc:56] dragonfly running in opt mode.
I20230326 05:15:07.822762     1 dfly_main.cc:476] Starting dragonfly df-v1.0.0-bb78c6eae3ad8a46f5bfc5fca8d99aed5758cd75
I20230326 05:15:07.822789     1 dfly_main.cc:499] maxmemory has not been specified. Deciding myself....
I20230326 05:15:07.822846     1 dfly_main.cc:504] Found 6.23GiB available memory. Setting maxmemory to 4.98GiB
I20230326 05:15:07.847543    19 proactor.cc:413] IORing with 1024 entries, allocated 102720 bytes, cq_entries is 2048
I20230326 05:15:07.875667     1 proactor_pool.cc:66] Running 12 io threads
I20230326 05:15:07.887950     1 server_family.cc:422] Data directory is "/data"
I20230326 05:15:07.888072    11 listener_interface.cc:86] sock[39] AcceptServer - listening on port 6379

  5. In steps 1-4 all fine

  6. Run benchmarks for Redis, KeyDB and DragonflyDB in Terminal 2

    docker exec research-online-redis-go-app go test ./... -v -bench=. -benchmem -benchtime=1000x -count=10 # or make bench
    BenchmarkKeydbHashOnlineStorage-12                      1000         15060 ns/op         373 B/op         10 allocs/op
BenchmarkKeydbHashOnlineStorage-12                      1000         14848 ns/op         379 B/op         10 allocs/op
BenchmarkKeydbHashOnlineStorage-12                      1000         14501 ns/op         378 B/op         10 allocs/op
BenchmarkDragonflydbHashOnlineStorage
online_storage_test.go:86: 
        Error Trace:    /go/src/github.com/doutivity/research-online-redis-go/online_storage_test.go:86
                                    /usr/local/go/src/testing/benchmark.go:815
                                    /usr/local/go/src/runtime/asm_amd64.s:1598
        Error:          Received unexpected error:
                        dial tcp: lookup dragonflydb1 on 127.0.0.11:53: server misbehaving
        Test:           BenchmarkDragonflydbHashOnlineStorage

  7. Go to logs in Terminal 1

    F20230326 05:18:15.663136    16 hset_family.cc:1112] Check failed: sm->AddOrUpdate(key, value) 
*** Check failure stack trace: ***
@     0x55a25f1b6c73  google::LogMessage::SendToLog()
@     0x55a25f1af437  google::LogMessage::Flush()
@     0x55a25f1b0dbf  google::LogMessageFatal::~LogMessageFatal()
@     0x55a25ee586bf  dfly::HSetFamily::ConvertToStrMap()
@     0x55a25ee58db3  dfly::(anonymous namespace)::OpSet()
@     0x55a25ee58fce  _ZNSt17_Function_handlerIFN6facade8OpStatusEPN4dfly11TransactionEPNS2_11EngineShardEEZNS3_18ScheduleSingleHopTIZNS2_10HSetFamily4HSetEN4absl12lts_202301254SpanINSC_IcEEEEPNS2_17ConnectionContextEEUlS4_S6_E_EEDTclfp_fpTLDn0EEEOT_EUlS4_S6_E_E9_M_invokeERKSt9_Any_dataOS4_OS6_
@     0x55a25eda5344  _ZNSt17_Function_handlerIFvvEZN4dfly11Transaction17ScheduleSingleHopESt8functionIFN6facade8OpStatusEPS2_PNS1_11EngineShardEEEEUlvE_E9_M_invokeERKSt9_Any_data.lto_priv.0
@     0x55a25ed6da61  util::fibers_ext::FiberQueue::Run()
@     0x55a25edc3138  _ZN5boost6fibers14worker_contextIZN4dfly11EngineShardC4EPN4util12ProactorBaseEbP9mi_heap_sEUlvE0_JEE4run_EONS_7context5fiberE
@     0x55a25edbc2a3  _ZN5boost7context6detail11fiber_entryINS1_12fiber_recordINS0_5fiberENS0_21basic_fixedsize_stackINS0_12stack_traitsEEESt5_BindIFMNS_6fibers14worker_contextIZN4dfly11EngineShardC4EPN4util12ProactorBaseEbP9mi_heap_sEUlvE0_JEEEFS4_OS4_EPSJ_St12_PlaceholderILi1EEEEEEEEvNS1_10transfer_tE
@     0x55a25f23c0bf  make_fcontext
*** SIGABRT received at time=1679807895 on cpu 7 ***
PC: @     0x7fbe5bb0700b  (unknown)  raise
[failure_signal_handler.cc : 332] RAW: Signal 11 raised at PC=0x7fbe5bae6941 while already in AbslFailureSignalHandler()
*** SIGSEGV received at time=1679807895 on cpu 7 ***
PC: @     0x7fbe5bae6941  (unknown)  abort

Expected behavior Have to success as Redis and KeyDB

Screenshots Already add logs

Environment (please complete the following information):

Reproducible Code Snippet https://github.com/doutivity/research-online-redis-go/tree/dragonflydb-server-misbehaving

Additional context When try run benchmarks with less iterations then DragonflyDB works:

docker exec research-online-redis-go-app go test ./... -v -bench=. -benchmem -benchtime=50x -count=10 | tee all-bench-10.txt
benchstat all-bench-10.txt
BenchmarkDragonflydbSortedSetOnlineStorage-12             50         23309 ns/op        2866 B/op         23 allocs/op
PASS
ok      github.com/doutivity/research-online-redis-go   1.190s
benchstat all-bench-10.txt
name                                  time/op
RedisHashOnlineStorage-12             79.1µs ±47%
KeydbHashOnlineStorage-12             43.0µs ±54%
DragonflydbHashOnlineStorage-12       27.9µs ±17%
RedisSortedSetOnlineStorage-12        25.5µs ± 8%
KeydbSortedSetOnlineStorage-12        28.8µs ±15%
DragonflydbSortedSetOnlineStorage-12  24.2µs ±11%

name                                  alloc/op
RedisHashOnlineStorage-12             2.96kB ± 2%
KeydbHashOnlineStorage-12             2.95kB ± 3%
DragonflydbHashOnlineStorage-12       2.86kB ± 3%
RedisSortedSetOnlineStorage-12        3.01kB ± 3%
KeydbSortedSetOnlineStorage-12        2.98kB ± 3%
DragonflydbSortedSetOnlineStorage-12  2.86kB ± 0%

name                                  allocs/op
RedisHashOnlineStorage-12               27.0 ± 0%
KeydbHashOnlineStorage-12               27.0 ± 0%
DragonflydbHashOnlineStorage-12         23.0 ± 0%
RedisSortedSetOnlineStorage-12          27.0 ± 0%
KeydbSortedSetOnlineStorage-12          27.0 ± 0%
DragonflydbSortedSetOnlineStorage-12    23.0 ± 0%
romange commented 1 year ago

@YaroslavPodorvanov thank you! Will be fixed.