ok: PSYNC2 #3899 regression: kill first replica
Logged warnings (pid 3128):
=== REDIS BUG REPORT START: Cut & paste starting from here ===
3128:M 01 May 2020 15:03:32.527 # Redis 6.0.0 crashed by signal: 11
3128:M 01 May 2020 15:03:32.527 # Crashed running the instruction at: 0x7f62cd883c01
3128:M 01 May 2020 15:03:32.527 # Accessing address: 0x558df8000000
3128:M 01 May 2020 15:03:32.527 # Failed assertion:
------ STACK TRACE ------ EIP: /lib/x86_64-linux-gnu/libc.so.6(cfree+0x2b1)[0x7f62cd883c01]
Backtrace: src/redis-server 127.0.0.1:21307(logStackTrace+0x5a)[0x558df7cc336a] src/redis-server 127.0.0.1:21307(sigsegvHandler+0xb1)[0x558df7cc3b21] /lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f62cdbef890] /lib/x86_64-linux-gnu/libc.so.6(cfree+0x2b1)[0x7f62cd883c01] src/redis-server 127.0.0.1:21307(listDelNode+0x37)[0x558df7c73dc7] src/redis-server 127.0.0.1:21307(writeToClient+0x24a)[0x558df7c8b8da] src/redis-server 127.0.0.1:21307(handleClientsWithPendingWrites+0x82)[0x558df7c8ba02] src/redis-server 127.0.0.1:21307(handleClientsWithPendingWritesUsingThreads+0x265)[0x558df7c913f5] src/redis-server 127.0.0.1:21307(beforeSleep+0xad)[0x558df7c7a76d] src/redis-server 127.0.0.1:21307(aeMain+0x1e)[0x558df7c770ee] src/redis-server 127.0.0.1:21307(main+0x52d)[0x558df7c737bd] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7)[0x7f62cd80db97] src/redis-server 127.0.0.1:21307(_start+0x2a)[0x558df7c73a1a]
------ INFO OUTPUT ------
Server
redis_version:6.0.0 redis_git_sha1:00000000 redis_git_dirty:0 redis_build_id:fd911d122c1dea24 redis_mode:standalone os:Linux 4.15.0-99-generic x86_64 arch_bits:64 multiplexing_api:epoll atomicvar_api:atomic-builtin gcc_version:7.5.0 process_id:3128 run_id:d41e59cb418c0b9291d39f6c09fc86687aec5116 tcp_port:21307 uptime_in_seconds:0 uptime_in_days:0 hz:10 configured_hz:10 lru_clock:11287108 executable:/home/verbus/redis-6.0.0/src/redis-server config_file:/home/verbus/redis-6.0.0/./tests/tmp/redis.conf.1671.31
Clients
connected_clients:1 client_recent_max_input_buffer:4 client_recent_max_output_buffer:0 blocked_clients:0 tracking_clients:0 clients_in_timeout_table:0
Memory
used_memory:945280 used_memory_human:923.12K used_memory_rss:4993024 used_memory_rss_human:4.76M used_memory_peak:945280 used_memory_peak_human:923.12K used_memory_peak_perc:105.78% used_memory_overhead:894012 used_memory_startup:876096 used_memory_dataset:51268 used_memory_dataset_perc:74.10% allocator_allocated:893624 allocator_active:4955136 allocator_resident:4955136 total_system_memory:8363720704 total_system_memory_human:7.79G used_memory_lua:44032 used_memory_lua_human:43.00K used_memory_scripts:928 used_memory_scripts_human:928B number_of_cached_scripts:8 maxmemory:0 maxmemory_human:0B maxmemory_policy:noeviction allocator_frag_ratio:5.54 allocator_frag_bytes:4061512 allocator_rss_ratio:1.00 allocator_rss_bytes:0 rss_overhead_ratio:1.01 rss_overhead_bytes:37888 mem_fragmentation_ratio:5.59 mem_fragmentation_bytes:4099400 mem_not_counted_for_evict:0 mem_replication_backlog:0 mem_clients_slaves:0 mem_clients_normal:16988 mem_aof_buffer:0 mem_allocator:libc active_defrag_running:0 lazyfree_pending_objects:0
Persistence
loading:0 rdb_changes_since_last_save:0 rdb_bgsave_in_progress:0 rdb_last_save_time:1588345412 rdb_last_bgsave_status:ok rdb_last_bgsave_time_sec:-1 rdb_current_bgsave_time_sec:-1 rdb_last_cow_size:0 aof_enabled:0 aof_rewrite_in_progress:0 aof_rewrite_scheduled:0 aof_last_rewrite_time_sec:-1 aof_current_rewrite_time_sec:-1 aof_last_bgrewrite_status:ok aof_last_write_status:ok aof_last_cow_size:0 module_fork_in_progress:0 module_fork_last_cow_size:0
Stats
total_connections_received:2 total_commands_processed:10 instantaneous_ops_per_sec:0 total_net_input_bytes:399 total_net_output_bytes:82 instantaneous_input_kbps:0.00 instantaneous_output_kbps:0.00 rejected_connections:0 sync_full:0 sync_partial_ok:0 sync_partial_err:0 expired_keys:0 expired_stale_perc:0.00 expired_time_cap_reached_count:0 expire_cycle_cpu_milliseconds:0 evicted_keys:0 keyspace_hits:0 keyspace_misses:0 pubsub_channels:0 pubsub_patterns:0 latest_fork_usec:0 migrate_cached_sockets:0 slave_expires_tracked_keys:0 active_defrag_hits:0 active_defrag_misses:0 active_defrag_key_hits:0 active_defrag_key_misses:0 tracking_total_keys:0 tracking_total_items:0 unexpected_error_replies:0
Replication
role:master connected_slaves:0 master_replid:6ded99b3fb22d028b6bdacdd54017dfe1fbcfdd6 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:0 master_repl_meaningful_offset:0 second_repl_offset:-1 repl_backlog_active:0 repl_backlog_size:1048576 repl_backlog_first_byte_offset:0 repl_backlog_histlen:0
CPU
used_cpu_sys:0.000000 used_cpu_user:0.008132 used_cpu_sys_children:0.000000 used_cpu_user_children:0.000000
Modules
Commandstats
cmdstat_eval:calls=8,usec=347,usec_per_call=43.38 cmdstat_select:calls=1,usec=2,usec_per_call=2.00 cmdstat_ping:calls=1,usec=1,usec_per_call=1.00
Cluster
cluster_enabled:0
Keyspace
------ CLIENT LIST OUTPUT ------ id=5 addr=127.0.0.1:45731 fd=8 name= age=0 idle=0 flags=N db=9 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=1 omem=40 events=r cmd=eval user=default
------ REGISTERS ------ 3128:M 01 May 2020 15:03:32.528 # RAX:0000558df8000000 RBX:00007f62cdbd7c40 RCX:0000000000000a00 RDX:0000000000000a08 RDI:0000558df91ff640 RSI:0000000000000a0d RBP:ffffffffffffff28 RSP:00007fff20955be0 R8 :0000000000000000 R9 :0000bcbc649d006d R10:0000000000000000 R11:0000000000000000 R12:0000558df91ff640 R13:0000558df91ff630 R14:000000000000000c R15:000000000000000c RIP:00007f62cd883c01 EFL:0000000000010206 CSGSFS:002b000000000033 3128:M 01 May 2020 15:03:32.528 # (00007fff20955bef) -> 0000558df9203980 3128:M 01 May 2020 15:03:32.528 # (00007fff20955bee) -> 0000000000000002 3128:M 01 May 2020 15:03:32.528 # (00007fff20955bed) -> 0000558df7c73dc7 3128:M 01 May 2020 15:03:32.528 # (00007fff20955bec) -> 000000000000000c 3128:M 01 May 2020 15:03:32.528 # (00007fff20955beb) -> 000000000000000c 3128:M 01 May 2020 15:03:32.528 # (00007fff20955bea) -> 0000558df91ff640 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be9) -> 0000558df9203bd8 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be8) -> 0000558df91ff530 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be7) -> 0000558df91fda60 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be6) -> 00007fff20955c60 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be5) -> 2324522307c77e00 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be4) -> 000000005eac3a44 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be3) -> 2324522307c77e00 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be2) -> 0000000000000000 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be1) -> 0000558df7c7dab2 3128:M 01 May 2020 15:03:32.528 # (00007fff20955be0) -> 0005a4977c182563
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------ 3128:M 01 May 2020 15:03:32.529 # Bio thread for job type #0 terminated 3128:M 01 May 2020 15:03:32.529 # Bio thread for job type #1 terminated 3128:M 01 May 2020 15:03:32.529 # Bio thread for job type #2 terminated *** Preparing to test memory region 558df7f8c000 (118784 bytes) *** Preparing to test memory region 558df9151000 (929792 bytes) *** Preparing to test memory region 7f62cb2ac000 (8388608 bytes) *** Preparing to test memory region 7f62cbaad000 (8388608 bytes) *** Preparing to test memory region 7f62cc2ae000 (8716288 bytes) *** Preparing to test memory region 7f62cd1a1000 (4096 bytes) *** Preparing to test memory region 7f62cdbd9000 (16384 bytes) *** Preparing to test memory region 7f62cddf8000 (16384 bytes) *** Preparing to test memory region 7f62ce07f000 (4096 bytes) *** Preparing to test memory region 7f62ce819000 (32768 bytes) *** Preparing to test memory region 7f62ce84b000 (4096 bytes) .O.O.O.O.O.O.O.O.O.O.O Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
------ DUMPING CODE AROUND EIP ------ Symbol: cfree (base: 0x7f62cd883950) Module: /lib/x86_64-linux-gnu/libc.so.6 (base 0x7f62cd7ec000) $ xxd -r -p /tmp/dump.hex /tmp/dump.bin $ objdump --adjust-vma=0x7f62cd883950 -D -b binary -m i386:x86-64 /tmp/dump.bin
3128:M 01 May 2020 15:03:33.168 # dump of function (hexdump of 817 bytes): 41574156415541544989fc55534883ec3864488b042528000000488944242831c0488b0570353500488b004885c00f859c0200004885ff0f8413010000488b77f84c8d6ff040f6c6020f8529010000488b2dd23335006448837d00000f84d604000040f6c604488d1d834235000f85350200004989f64983e6f84c89f048f7d84c39e80f823704000041f6c50f0f852d0400004983fe1f0f863304000040f6c6080f852904000064488b55004885d27426498d46ef48c1e804483b05c03835007315480fbe3c02483b3dc23835004889f90f82090400004c3b35125f35000f87fc0100004b8d543500488b42084883f8100f86890400004883e0f8483b83880800000f83780400008b05ce5e350085c00f8547060000c7430801000000488d35848e350041c1ee04418d4efe8b36488d04cb488b501085f60f85110500004939d50f8461050000498914244c89681090488b4424286448330425280000000f85940900004883c4385b5d415c415d415e415fc30f1f4400008b3de6373500488b05635e350085ff0f85c3000000483b35ac3735000f86b60000004881fe000000020f87a90000004939c50f83900000004883e6f8488d0436488935813735004889056a37350090498b7424f840f6c6020f85310c0000488b05c3323500488d0d45c11100488d1d05d2110041b90f0b0000488b10488d0585c31100803a00480f45c84883ec085350488d0509151200504c8d0591d11100488d35ea0b120031ff31c0e85962feff488b05323235004883c420488b38e8566cfeffe8318bfaff904c3b2d995d35000f8363ffffff0f1f004883e6f84939c57367498b4424f04c89ef4829c74801c6488b059a3235004889fa4809f2488b40184883e8014885d00f85eb020000f0ff0dcc3635004889f048f7d8f0480105ce363500e8c13e0800e9acfeffff0f1f40004c89e84825000000fc488b18e9bafdffff0f1f80000000004c3b2d195d35007390e982feffff6690488b742468ffd0e974feffff0f1f400083e6020f8577020000488d05b88c3500bd010000008b0085c00f859c040000488b43604f8d7c35004939c50f84c1040000f64304020f84ea010000498b4708a8010f84010200004889c14883e1f84883f8 Function at 0x7f62cd86a7e0 is fflush Function at 0x7f62cd82c6c0 is abort Function at 0x7f62cd907ab0 is __munmap Function at 0x7f62cd886147 is __libc_calloc
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
Please report the crash by opening an issue on github:
http://github.com/antirez/redis/issues
Suspect RAM error? Use redis-server --test-memory to verify it.
Comment From: antirez
Thank you for your bug report. Checking. ping @oranagra.
Comment From: antirez
@verbus P.S. is this reproducible in your environment?
Comment From: antirez
@verbus Sorry another question, did you modified the config file in order to use io-threads and re-executed the tests?
Comment From: verbus
P.S. is this reproducible in your environment? Yes.
Sorry another question, did you modified the config file in order to use io-threads and re-executed the tests? No.
Comment From: oranagra
@verbus can you please run the tests with --clients 1
thing is that we know which test passed last, but that doesn't necessarily means which test was the one that failed.
alternatively, maybe you have a print in the console with the TCL test code stack trace?
Comment From: antirez
@oranagra interesting thing I noticed, wanted to make sure you see this as well: uptime is 0 seconds, the instance crashes immediately for some reason, apparently because it receives an EVAL command, but 0 seconds uptime is a bit odd.
Comment From: antirez
@oranagra also from the INFO output looks like it's not really a replication related test.
Comment From: verbus
This is where it fails running:
Run the builtin test
time make -j4 test || { echo "Error----> make test failed." >&2; exit 6; }
24/53 done]: unit/slowlog (2 seconds) Testing unit/maxmemory ok: PSYNC2: cluster is consistent after failover ok: Without maxmemory small integers are shared ok: With maxmemory and non-LRU policy integers are still shared ok: With maxmemory and LRU policy integers are not shared ok: PSYNC2 #3899 regression: kill first replica
Logged warnings (pid 15264):
=== REDIS BUG REPORT START: Cut & paste starting from here ===
15264:M 01 May 2020 16:38:56.998 # Redis 6.0.0 crashed by signal: 11
15264:M 01 May 2020 16:38:56.998 # Crashed running the instruction at: 0x7f2340eabc01
15264:M 01 May 2020 16:38:56.998 # Accessing address: 0x562ee4000000
15264:M 01 May 2020 16:38:56.998 # Failed assertion:
------ STACK TRACE ------
Comment From: antirez
@verbus thank you a lot. Please consider that for us your environment that can reproduce the crash consistently is very important! I will really appreciate if you can leave it in the current state if possible for you. Thanks :-)
Comment From: antirez
@verbus it is still not clear where it fails however, if you can run the test like this:
build Redis as usually with make, then run:
./runtest --clients 1
Comment From: verbus
I will leave the environment as is for now.
Comment From: oranagra
@verbus please run ./runtest --clients 1 then tell us which test was the last one that finished just before the crash.
and also, maybe there are some prints after the redis crash log, containing the test code stack trace?
Comment From: verbus
verbus@ubuntu-s-4vcpu-8gb-nyc3-01:~/redis-6.0.0$ ./runtest --clients 1 Cleanup: may take some time... OK Starting test server at port 11111
Testing unit/printver Testing Redis version 6.0.0 (00000000)
Testing unit/dump ok: DUMP / RESTORE are able to serialize / unserialize a simple key ok: RESTORE can set an arbitrary expire to the materialized key ok: RESTORE can set an expire that overflows a 32 bit integer ok: RESTORE can set an absolute expire ok: RESTORE can set LRU ok: RESTORE can set LFU ok: RESTORE returns an error of the key already exists ok: RESTORE can overwrite an existing key with REPLACE ok: RESTORE can detect a syntax error for unrecongized options ok: DUMP of non existing key returns nil ok: MIGRATE is caching connections ok: MIGRATE cached connections are released after some time ok: MIGRATE is able to migrate a key between two instances ok: MIGRATE is able to copy a key between two instances ok: MIGRATE will not overwrite existing keys, unless REPLACE is used ok: MIGRATE propagates TTL correctly ok: MIGRATE can correctly transfer large values ok: MIGRATE can correctly transfer hashes ok: MIGRATE timeout actually works ok: MIGRATE can migrate multiple keys at once ok: MIGRATE with multiple keys must have empty key arg ok: MIGRATE with multiple keys migrate just existing ones ok: MIGRATE with multiple keys: stress command rewriting ok: MIGRATE with multiple keys: delete just ack keys ok: MIGRATE AUTH: correct and wrong password cases
Testing unit/auth ok: AUTH fails if there is no password configured server side ok: AUTH fails when a wrong password is given ok: Arbitrary command gives an error when AUTH is required ok: AUTH succeeds when the right password is given ok: Once AUTH succeeded we can actually send commands to the server
Testing unit/protocol ok: Handle an empty query ok: Negative multibulk length ok: Out of range multibulk length ok: Wrong multibulk payload header ok: Negative multibulk payload length ok: Out of range multibulk payload length ok: Non-number multibulk payload length ok: Multi bulk request not followed by bulk arguments ok: Generic wrong number of args ok: Unbalanced number of quotes ok: Protocol desync regression test #1 ok: Protocol desync regression test #2 ok: Protocol desync regression test #3 ok: Regression for a crash with blocking ops and pipelining
Testing unit/keyspace ok: DEL against a single item ok: Vararg DEL ok: KEYS with pattern ok: KEYS to get all keys
ok: DEL all keys ok: DEL against expired key
ok: Zero length value in key. SET/GET/EXISTS ok: Commands pipelining ok: Non existing command ok: RENAME basic usage ok: RENAME source key should no longer exist ok: RENAME against already existing key ok: RENAMENX basic usage ok: RENAMENX against already existing key ok: RENAMENX against already existing key (2) ok: RENAME against non existing source key ok: RENAME where source and dest key are the same (existing) ok: RENAMENX where source and dest key are the same (existing) ok: RENAME where source and dest key are the same (non existing) ok: RENAME with volatile key, should move the TTL as well ok: RENAME with volatile key, should not inherit TTL of target key ok: DEL all keys again (DB 0) ok: DEL all keys again (DB 1) ok: MOVE basic usage ok: MOVE against key existing in the target DB ok: MOVE against non-integer DB (#1428) ok: MOVE can move key expire metadata as well ok: MOVE does not create an expire if it does not exist ok: SET/GET keys in different DBs
ok: RANDOMKEY against empty DB ok: RANDOMKEY regression 1 ok: KEYS * two times with long key, Github issue #1208
Testing unit/scan ok: SCAN basic ok: SCAN COUNT ok: SCAN MATCH ok: SCAN TYPE ok: SSCAN with encoding intset ok: SSCAN with encoding hashtable ok: HSCAN with encoding ziplist ok: HSCAN with encoding hashtable ok: ZSCAN with encoding ziplist ok: ZSCAN with encoding skiplist ok: SCAN guarantees check under write load ok: SSCAN with integer encoded object (issue #1345) ok: SSCAN with PATTERN ok: HSCAN with PATTERN ok: ZSCAN with PATTERN ok: ZSCAN scores: regression test for issue #2175 ok: SCAN regression test for issue #4906
Testing unit/type/string ok: SET and GET an item ok: SET and GET an empty item ok: Very big payload in GET/SET ok: Very big payload random access ok: SET 10000 numeric keys and access all them in reverse order ok: DBSIZE should be 10000 now ok: SETNX target key missing ok: SETNX target key exists ok: SETNX against not-expired volatile key ok: SETNX against expired volatile key
ok: MGET against non existing key ok: MGET against non-string key
ok: MSET base case ok: MSET wrong number of args ok: MSETNX with already existent key ok: MSETNX with not existing keys ok: STRLEN against non-existing key ok: STRLEN against integer-encoded value ok: STRLEN against plain string ok: SETBIT against non-existing key ok: SETBIT against string-encoded key ok: SETBIT against integer-encoded key ok: SETBIT against key with wrong type ok: SETBIT with out of range bit offset ok: SETBIT with non-bit argument ok: SETBIT fuzzing ok: GETBIT against non-existing key ok: GETBIT against string-encoded key ok: GETBIT against integer-encoded key ok: SETRANGE against non-existing key ok: SETRANGE against string-encoded key ok: SETRANGE against integer-encoded key ok: SETRANGE against key with wrong type ok: SETRANGE with out of range offset ok: GETRANGE against non-existing key ok: GETRANGE against string value ok: GETRANGE against integer-encoded value ok: GETRANGE fuzzing ok: Extended SET can detect syntax errors ok: Extended SET NX option ok: Extended SET XX option ok: Extended SET EX option ok: Extended SET PX option ok: Extended SET using multiple options at once ok: GETRANGE with huge ranges, Github issue #1844 ok: STRALGO LCS string output with STRINGS option ok: STRALGO LCS len ok: LCS with KEYS option ok: LCS indexes ok: LCS indexes with match len ok: LCS indexes with match len and minimum match len
Testing unit/type/incr ok: INCR against non existing key ok: INCR against key created by incr itself ok: INCR against key originally set with SET ok: INCR over 32bit value ok: INCRBY over 32bit value with over 32bit increment ok: INCR fails against key with spaces (left) ok: INCR fails against key with spaces (right) ok: INCR fails against key with spaces (both) ok: INCR fails against a key holding a list ok: DECRBY over 32bit value with over 32bit increment, negative res ok: INCR uses shared objects in the 0-9999 range ok: INCR can modify objects in-place ok: INCRBYFLOAT against non existing key ok: INCRBYFLOAT against key originally set with SET ok: INCRBYFLOAT over 32bit value ok: INCRBYFLOAT over 32bit value with over 32bit increment ok: INCRBYFLOAT fails against key with spaces (left) ok: INCRBYFLOAT fails against key with spaces (right) ok: INCRBYFLOAT fails against key with spaces (both) ok: INCRBYFLOAT fails against a key holding a list ok: INCRBYFLOAT does not allow NaN or Infinity ok: INCRBYFLOAT decrement ok: string to double with null terminator ok: No negative zero
Testing unit/type/list ok: LPUSH, RPUSH, LLENGTH, LINDEX, LPOP - ziplist ok: LPUSH, RPUSH, LLENGTH, LINDEX, LPOP - regular list ok: R/LPOP against empty list ok: Variadic RPUSH/LPUSH ok: DEL a list ok: BLPOP, BRPOP: single existing list - linkedlist ok: BLPOP, BRPOP: multiple existing lists - linkedlist ok: BLPOP, BRPOP: second list has an entry - linkedlist ok: BRPOPLPUSH - linkedlist ok: BLPOP, BRPOP: single existing list - ziplist ok: BLPOP, BRPOP: multiple existing lists - ziplist ok: BLPOP, BRPOP: second list has an entry - ziplist ok: BRPOPLPUSH - ziplist ok: BLPOP, LPUSH + DEL should not awake blocked client ok: BLPOP, LPUSH + DEL + SET should not awake blocked client ok: BLPOP with same key multiple times should work (issue #801) ok: MULTI/EXEC is isolated from the point of view of BLPOP ok: BLPOP with variadic LPUSH ok: BRPOPLPUSH with zero timeout should block indefinitely ok: BRPOPLPUSH with a client BLPOPing the target list ok: BRPOPLPUSH with wrong source type ok: BRPOPLPUSH with wrong destination type ok: BRPOPLPUSH maintains order of elements after failure ok: BRPOPLPUSH with multiple blocked clients ok: Linked BRPOPLPUSH ok: Circular BRPOPLPUSH ok: Self-referential BRPOPLPUSH ok: BRPOPLPUSH inside a transaction ok: PUSH resulting from BRPOPLPUSH affect WATCH ok: BRPOPLPUSH does not affect WATCH while still blocked ok: BRPOPLPUSH timeout ok: BLPOP when new key is moved into place ok: BLPOP when result key is created by SORT..STORE ok: BLPOP: with single empty list argument ok: BLPOP: with negative timeout ok: BLPOP: with non-integer timeout ok: BLPOP: with zero timeout should block indefinitely ok: BLPOP: second argument is not a list ok: BLPOP: timeout ok: BLPOP: arguments are empty ok: BRPOP: with single empty list argument ok: BRPOP: with negative timeout ok: BRPOP: with non-integer timeout ok: BRPOP: with zero timeout should block indefinitely ok: BRPOP: second argument is not a list ok: BRPOP: timeout ok: BRPOP: arguments are empty ok: BLPOP inside a transaction ok: LPUSHX, RPUSHX - generic ok: LPUSHX, RPUSHX - linkedlist ok: LINSERT - linkedlist ok: LPUSHX, RPUSHX - ziplist ok: LINSERT - ziplist ok: LINSERT raise error on bad syntax ok: LINDEX consistency test - quicklist ok: LINDEX random access - quicklist ok: Check if list is still ok after a DEBUG RELOAD - quicklist ok: LINDEX consistency test - quicklist ok: LINDEX random access - quicklist ok: Check if list is still ok after a DEBUG RELOAD - quicklist ok: LLEN against non-list value error ok: LLEN against non existing key ok: LINDEX against non-list value error ok: LINDEX against non existing key ok: LPUSH against non-list value error ok: RPUSH against non-list value error ok: RPOPLPUSH base case - linkedlist ok: RPOPLPUSH with the same list as src and dst - linkedlist ok: RPOPLPUSH with linkedlist source and existing target linkedlist ok: RPOPLPUSH with linkedlist source and existing target ziplist ok: RPOPLPUSH base case - ziplist ok: RPOPLPUSH with the same list as src and dst - ziplist ok: RPOPLPUSH with ziplist source and existing target linkedlist ok: RPOPLPUSH with ziplist source and existing target ziplist ok: RPOPLPUSH against non existing key ok: RPOPLPUSH against non list src key ok: RPOPLPUSH against non list dst key ok: RPOPLPUSH against non existing src key ok: Basic LPOP/RPOP - linkedlist ok: Basic LPOP/RPOP - ziplist ok: LPOP/RPOP against non list value ok: Mass RPOP/LPOP - quicklist ok: Mass RPOP/LPOP - quicklist ok: LRANGE basics - linkedlist ok: LRANGE inverted indexes - linkedlist ok: LRANGE out of range indexes including the full list - linkedlist ok: LRANGE out of range negative end index - linkedlist ok: LRANGE basics - ziplist ok: LRANGE inverted indexes - ziplist ok: LRANGE out of range indexes including the full list - ziplist ok: LRANGE out of range negative end index - ziplist ok: LRANGE against non existing key ok: LTRIM basics - linkedlist ok: LTRIM out of range negative end index - linkedlist ok: LTRIM basics - ziplist ok: LTRIM out of range negative end index - ziplist ok: LSET - linkedlist ok: LSET out of range index - linkedlist ok: LSET - ziplist ok: LSET out of range index - ziplist ok: LSET against non existing key ok: LSET against non list value ok: LREM remove all the occurrences - linkedlist ok: LREM remove the first occurrence - linkedlist ok: LREM remove non existing element - linkedlist ok: LREM starting from tail with negative count - linkedlist ok: LREM starting from tail with negative count (2) - linkedlist ok: LREM deleting objects that may be int encoded - linkedlist ok: LREM remove all the occurrences - ziplist ok: LREM remove the first occurrence - ziplist ok: LREM remove non existing element - ziplist ok: LREM starting from tail with negative count - ziplist ok: LREM starting from tail with negative count (2) - ziplist ok: LREM deleting objects that may be int encoded - ziplist ok: Regression for bug 593 - chaining BRPOPLPUSH with other blocking cmds
Testing unit/type/list-2 ok: LTRIM stress testing - linkedlist ok: LTRIM stress testing - ziplist
Testing unit/type/list-3 ok: Explicit regression for a list bug ok: Regression for quicklist #3343 bug ok: Stress tester for #3343-alike bugs ok: ziplist implementation: value encoding and backlink ok: ziplist implementation: encoding stress testing
Testing unit/type/set
ok: SADD, SCARD, SISMEMBER, SMEMBERS basics - regular set
ok: SADD, SCARD, SISMEMBER, SMEMBERS basics - intset
ok: SADD against non set
ok: SADD a non-integer against an intset
ok: SADD an integer larger than 64 bits
ok: SADD overflows the maximum allowed integers in an intset
ok: Variadic SADD
ok: Set encoding after DEBUG RELOAD
ok: SREM basics - regular set
ok: SREM basics - intset
ok: SREM with multiple arguments
ok: SREM variadic version with more args needed to destroy the key
ok: Generated sets must be encoded as hashtable
ok: SINTER with two sets - hashtable
ok: SINTERSTORE with two sets - hashtable
ok: SINTERSTORE with two sets, after a DEBUG RELOAD - hashtable
ok: SUNION with two sets - hashtable
ok: SUNIONSTORE with two sets - hashtable
ok: SINTER against three sets - hashtable
ok: SINTERSTORE with three sets - hashtable
ok: SUNION with non existing keys - hashtable
ok: SDIFF with two sets - hashtable
ok: SDIFF with three sets - hashtable
ok: SDIFFSTORE with three sets - hashtable
ok: Generated sets must be encoded as intset
ok: SINTER with two sets - intset
ok: SINTERSTORE with two sets - intset
ok: SINTERSTORE with two sets, after a DEBUG RELOAD - intset
ok: SUNION with two sets - intset
ok: SUNIONSTORE with two sets - intset
ok: SINTER against three sets - intset
ok: SINTERSTORE with three sets - intset
ok: SUNION with non existing keys - intset
ok: SDIFF with two sets - intset
ok: SDIFF with three sets - intset
ok: SDIFFSTORE with three sets - intset
ok: SDIFF with first set empty
ok: SDIFF with same set two times
ok: SDIFF fuzzing
ok: SINTER against non-set should throw error
ok: SUNION against non-set should throw error
ok: SINTER should handle non existing key as empty
ok: SINTER with same integer elements but different encoding
ok: SINTERSTORE against non existing keys should delete dstkey
ok: SUNIONSTORE against non existing keys should delete dstkey
ok: SPOP basics - hashtable
ok: SPOP with
Testing unit/type/zset ok: Check encoding - ziplist ok: ZSET basic ZADD and score update - ziplist ok: ZSET element can't be set to NaN with ZADD - ziplist ok: ZSET element can't be set to NaN with ZINCRBY ok: ZADD with options syntax error with incomplete pair ok: ZADD XX option without key - ziplist ok: ZADD XX existing key - ziplist ok: ZADD XX returns the number of elements actually added ok: ZADD XX updates existing elements score ok: ZADD XX and NX are not compatible ok: ZADD NX with non existing key ok: ZADD NX only add new elements without updating old ones ok: ZADD INCR works like ZINCRBY ok: ZADD INCR works with a single score-elemenet pair ok: ZADD CH option changes return value to all changed elements ok: ZINCRBY calls leading to NaN result in error ok: ZADD - Variadic version base case ok: ZADD - Return value is the number of actually added items ok: ZADD - Variadic version does not add nothing on single parsing err ok: ZADD - Variadic version will raise error on missing arg ok: ZINCRBY does not work variadic even if shares ZADD implementation ok: ZCARD basics - ziplist ok: ZREM removes key after last element is removed ok: ZREM variadic version ok: ZREM variadic version -- remove elements after key deletion ok: ZRANGE basics - ziplist ok: ZREVRANGE basics - ziplist ok: ZRANK/ZREVRANK basics - ziplist ok: ZRANK - after deletion - ziplist ok: ZINCRBY - can create a new sorted set - ziplist ok: ZINCRBY - increment and decrement - ziplist ok: ZINCRBY return value ok: ZRANGEBYSCORE/ZREVRANGEBYSCORE/ZCOUNT basics ok: ZRANGEBYSCORE with WITHSCORES ok: ZRANGEBYSCORE with LIMIT ok: ZRANGEBYSCORE with LIMIT and WITHSCORES ok: ZRANGEBYSCORE with non-value min or max ok: ZRANGEBYLEX/ZREVRANGEBYLEX/ZLEXCOUNT basics ok: ZLEXCOUNT advanced ok: ZRANGEBYSLEX with LIMIT ok: ZRANGEBYLEX with invalid lex range specifiers ok: ZREMRANGEBYSCORE basics ok: ZREMRANGEBYSCORE with non-value min or max ok: ZREMRANGEBYRANK basics ok: ZUNIONSTORE against non-existing key doesn't set destination - ziplist ok: ZUNIONSTORE with empty set - ziplist ok: ZUNIONSTORE basics - ziplist ok: ZUNIONSTORE with weights - ziplist ok: ZUNIONSTORE with a regular set and weights - ziplist ok: ZUNIONSTORE with AGGREGATE MIN - ziplist ok: ZUNIONSTORE with AGGREGATE MAX - ziplist ok: ZINTERSTORE basics - ziplist ok: ZINTERSTORE with weights - ziplist ok: ZINTERSTORE with a regular set and weights - ziplist ok: ZINTERSTORE with AGGREGATE MIN - ziplist ok: ZINTERSTORE with AGGREGATE MAX - ziplist ok: ZUNIONSTORE with +inf/-inf scores - ziplist ok: ZUNIONSTORE with NaN weights ziplist ok: ZINTERSTORE with +inf/-inf scores - ziplist ok: ZINTERSTORE with NaN weights ziplist ok: Basic ZPOP with a single key - ziplist ok: ZPOP with count - ziplist ok: BZPOP with a single existing sorted set - ziplist ok: BZPOP with multiple existing sorted sets - ziplist ok: BZPOP second sorted set has members - ziplist ok: Check encoding - skiplist ok: ZSET basic ZADD and score update - skiplist ok: ZSET element can't be set to NaN with ZADD - skiplist ok: ZSET element can't be set to NaN with ZINCRBY ok: ZADD with options syntax error with incomplete pair ok: ZADD XX option without key - skiplist ok: ZADD XX existing key - skiplist ok: ZADD XX returns the number of elements actually added ok: ZADD XX updates existing elements score ok: ZADD XX and NX are not compatible ok: ZADD NX with non existing key ok: ZADD NX only add new elements without updating old ones ok: ZADD INCR works like ZINCRBY ok: ZADD INCR works with a single score-elemenet pair ok: ZADD CH option changes return value to all changed elements ok: ZINCRBY calls leading to NaN result in error ok: ZADD - Variadic version base case ok: ZADD - Return value is the number of actually added items ok: ZADD - Variadic version does not add nothing on single parsing err ok: ZADD - Variadic version will raise error on missing arg ok: ZINCRBY does not work variadic even if shares ZADD implementation ok: ZCARD basics - skiplist ok: ZREM removes key after last element is removed ok: ZREM variadic version ok: ZREM variadic version -- remove elements after key deletion ok: ZRANGE basics - skiplist ok: ZREVRANGE basics - skiplist ok: ZRANK/ZREVRANK basics - skiplist ok: ZRANK - after deletion - skiplist ok: ZINCRBY - can create a new sorted set - skiplist ok: ZINCRBY - increment and decrement - skiplist ok: ZINCRBY return value ok: ZRANGEBYSCORE/ZREVRANGEBYSCORE/ZCOUNT basics ok: ZRANGEBYSCORE with WITHSCORES ok: ZRANGEBYSCORE with LIMIT ok: ZRANGEBYSCORE with LIMIT and WITHSCORES ok: ZRANGEBYSCORE with non-value min or max ok: ZRANGEBYLEX/ZREVRANGEBYLEX/ZLEXCOUNT basics ok: ZLEXCOUNT advanced ok: ZRANGEBYSLEX with LIMIT ok: ZRANGEBYLEX with invalid lex range specifiers ok: ZREMRANGEBYSCORE basics ok: ZREMRANGEBYSCORE with non-value min or max ok: ZREMRANGEBYRANK basics ok: ZUNIONSTORE against non-existing key doesn't set destination - skiplist ok: ZUNIONSTORE with empty set - skiplist ok: ZUNIONSTORE basics - skiplist ok: ZUNIONSTORE with weights - skiplist ok: ZUNIONSTORE with a regular set and weights - skiplist ok: ZUNIONSTORE with AGGREGATE MIN - skiplist ok: ZUNIONSTORE with AGGREGATE MAX - skiplist ok: ZINTERSTORE basics - skiplist ok: ZINTERSTORE with weights - skiplist ok: ZINTERSTORE with a regular set and weights - skiplist ok: ZINTERSTORE with AGGREGATE MIN - skiplist ok: ZINTERSTORE with AGGREGATE MAX - skiplist ok: ZUNIONSTORE with +inf/-inf scores - skiplist ok: ZUNIONSTORE with NaN weights skiplist ok: ZINTERSTORE with +inf/-inf scores - skiplist ok: ZINTERSTORE with NaN weights skiplist ok: Basic ZPOP with a single key - skiplist ok: ZPOP with count - skiplist ok: BZPOP with a single existing sorted set - skiplist ok: BZPOP with multiple existing sorted sets - skiplist ok: BZPOP second sorted set has members - skiplist ok: ZINTERSTORE regression with two sets, intset+hashtable ok: ZUNIONSTORE regression, should not create NaN in scores ok: ZINTERSTORE #516 regression, mixed sets and ziplist zsets ok: ZUNIONSTORE result is sorted ok: ZSET commands don't accept the empty strings as valid score ok: ZSCORE - ziplist ok: ZSCORE after a DEBUG RELOAD - ziplist ok: ZSET sorting stresser - ziplist ok: ZRANGEBYSCORE fuzzy test, 100 ranges in 128 element sorted set - ziplist ok: ZRANGEBYLEX fuzzy test, 100 ranges in 128 element sorted set - ziplist ok: ZREMRANGEBYLEX fuzzy test, 100 ranges in 128 element sorted set - ziplist ok: ZSETs skiplist implementation backlink consistency test - ziplist ok: ZSETs ZRANK augmented skip list stress testing - ziplist ok: BZPOPMIN, ZADD + DEL should not awake blocked client ok: BZPOPMIN, ZADD + DEL + SET should not awake blocked client ok: BZPOPMIN with same key multiple times should work ok: MULTI/EXEC is isolated from the point of view of BZPOPMIN ok: BZPOPMIN with variadic ZADD ok: BZPOPMIN with zero timeout should block indefinitely ok: ZSCORE - skiplist ok: ZSCORE after a DEBUG RELOAD - skiplist ok: ZSET sorting stresser - skiplist ok: ZRANGEBYSCORE fuzzy test, 100 ranges in 100 element sorted set - skiplist ok: ZRANGEBYLEX fuzzy test, 100 ranges in 100 element sorted set - skiplist ok: ZREMRANGEBYLEX fuzzy test, 100 ranges in 100 element sorted set - skiplist ok: ZSETs skiplist implementation backlink consistency test - skiplist ok: ZSETs ZRANK augmented skip list stress testing - skiplist ok: BZPOPMIN, ZADD + DEL should not awake blocked client ok: BZPOPMIN, ZADD + DEL + SET should not awake blocked client ok: BZPOPMIN with same key multiple times should work ok: MULTI/EXEC is isolated from the point of view of BZPOPMIN ok: BZPOPMIN with variadic ZADD ok: BZPOPMIN with zero timeout should block indefinitely ok: ZSET skiplist order consistency when elements are moved
Testing unit/type/hash ok: HSET/HLEN - Small hash creation ok: Is the small hash encoded with a ziplist? ok: HSET/HLEN - Big hash creation ok: Is the big hash encoded with an hash table? ok: HGET against the small hash ok: HGET against the big hash ok: HGET against non existing key ok: HSET in update and insert mode ok: HSETNX target key missing - small hash ok: HSETNX target key exists - small hash ok: HSETNX target key missing - big hash ok: HSETNX target key exists - big hash ok: HMSET wrong number of args ok: HMSET - small hash ok: HMSET - big hash ok: HMGET against non existing key and fields ok: HMGET against wrong type ok: HMGET - small hash ok: HMGET - big hash ok: HKEYS - small hash ok: HKEYS - big hash ok: HVALS - small hash ok: HVALS - big hash ok: HGETALL - small hash ok: HGETALL - big hash ok: HDEL and return value ok: HDEL - more than a single value ok: HDEL - hash becomes empty before deleting all specified fields
ok: Is a ziplist encoded Hash promoted on big payload? ok: HINCRBY against non existing database key ok: HINCRBY against non existing hash key ok: HINCRBY against hash key created by hincrby itself ok: HINCRBY against hash key originally set with HSET ok: HINCRBY over 32bit value ok: HINCRBY over 32bit value with over 32bit increment ok: HINCRBY fails against hash value with spaces (left) ok: HINCRBY fails against hash value with spaces (right) ok: HINCRBY can detect overflows ok: HINCRBYFLOAT against non existing database key ok: HINCRBYFLOAT against non existing hash key ok: HINCRBYFLOAT against hash key created by hincrby itself ok: HINCRBYFLOAT against hash key originally set with HSET ok: HINCRBYFLOAT over 32bit value ok: HINCRBYFLOAT over 32bit value with over 32bit increment ok: HINCRBYFLOAT fails against hash value with spaces (left) ok: HINCRBYFLOAT fails against hash value with spaces (right) ok: HINCRBYFLOAT fails against hash value that contains a null-terminator in the middle ok: HSTRLEN against the small hash ok: HSTRLEN against the big hash ok: HSTRLEN against non existing field ok: HSTRLEN corner cases ok: Hash ziplist regression test for large keys ok: Hash fuzzing #1 - 10 fields ok: Hash fuzzing #2 - 10 fields ok: Hash fuzzing #1 - 512 fields ok: Hash fuzzing #2 - 512 fields ok: Stress test the hash ziplist -> hashtable encoding conversion ok: Test HINCRBYFLOAT for correct float representation (issue #2846)
Testing unit/type/stream ok: XADD can add entries into a stream that XRANGE can fetch ok: XADD IDs are incremental ok: XADD IDs are incremental when ms is the same as well ok: XADD IDs correctly report an error when overflowing ok: XADD with MAXLEN option ok: XADD mass insertion and XLEN ok: XADD with ID 0-0 ok: XRANGE COUNT works as expected ok: XREVRANGE COUNT works as expected ok: XRANGE can be used to iterate the whole stream ok: XREVRANGE returns the reverse of XRANGE ok: XREAD with non empty stream ok: Non blocking XREAD with empty streams ok: XREAD with non empty second stream ok: Blocking XREAD waiting new data ok: Blocking XREAD waiting old data ok: Blocking XREAD will not reply with an empty array ok: XREAD: XADD + DEL should not awake client ok: XREAD: XADD + DEL + LPUSH should not awake client ok: XREAD with same stream name multiple times should work ok: XREAD + multiple XADD inside transaction ok: XDEL basic test ok: XDEL fuzz test ok: XRANGE fuzzing ok: XREVRANGE regression test for issue #5006 ok: XREAD streamID edge (no-blocking) ok: XREAD streamID edge (blocking) ok: XADD streamID edge ok: XADD with MAXLEN > xlen can propagate correctly ok: XADD with ~ MAXLEN can propagate correctly ok: XTRIM with ~ MAXLEN can propagate correctly ok: XADD can CREATE an empty stream ok: XSETID can set a specific ID ok: XSETID cannot SETID with smaller ID ok: XSETID cannot SETID on non-existent key ok: Empty stream can be rewrite into AOF correctly ok: Stream can be rewrite into AOF correctly after XDEL lastid
Testing unit/type/stream-cgroups ok: XGROUP CREATE: creation and duplicate group name detection ok: XGROUP CREATE: automatic stream creation fails without MKSTREAM ok: XGROUP CREATE: automatic stream creation works with MKSTREAM ok: XREADGROUP will return only new elements ok: XREADGROUP can read the history of the elements we own ok: XPENDING is able to return pending items ok: XPENDING can return single consumer items ok: XACK is able to remove items from the client/group PEL ok: XACK can't remove the same item multiple times ok: XACK is able to accept multiple arguments ok: XACK should fail if got at least one invalid ID ok: PEL NACK reassignment after XGROUP SETID event ok: XREADGROUP will not report data on empty history. Bug #5577 ok: XREADGROUP history reporting of deleted entries. Bug #5570 ok: Blocking XREADGROUP will not reply with an empty array ok: XGROUP DESTROY should unblock XREADGROUP with -NOGROUP ok: RENAME can unblock XREADGROUP with data ok: RENAME can unblock XREADGROUP with -NOGROUP ok: XCLAIM can claim PEL items from another consumer ok: XCLAIM without JUSTID increments delivery count ok: XINFO FULL output ok: Consumer group last ID propagation to slave (NOACK=0) ok: Consumer group last ID propagation to slave (NOACK=1) ok: Empty stream with no lastid can be rewrite into AOF correctly
Testing unit/sort
ok: Old Ziplist: SORT BY key
ok: Old Ziplist: SORT BY key with limit
ok: Old Ziplist: SORT BY hash field
ok: Old Linked list: SORT BY key
ok: Old Linked list: SORT BY key with limit
ok: Old Linked list: SORT BY hash field
ok: Old Big Linked list: SORT BY key
ok: Old Big Linked list: SORT BY key with limit
ok: Old Big Linked list: SORT BY hash field
ok: Intset: SORT BY key
ok: Intset: SORT BY key with limit
ok: Intset: SORT BY hash field
ok: Hash table: SORT BY key
ok: Hash table: SORT BY key with limit
ok: Hash table: SORT BY hash field
ok: Big Hash table: SORT BY key
ok: Big Hash table: SORT BY key with limit
ok: Big Hash table: SORT BY hash field
ok: SORT GET #
ok: SORT GET
Logged warnings (pid 18576):
=== REDIS BUG REPORT START: Cut & paste starting from here ===
18576:M 01 May 2020 16:56:50.705 # Redis 6.0.0 crashed by signal: 11
18576:M 01 May 2020 16:56:50.705 # Crashed running the instruction at: 0x7f6d14438c01
18576:M 01 May 2020 16:56:50.705 # Accessing address: 0x555dd4000000
18576:M 01 May 2020 16:56:50.705 # Failed assertion:
------ STACK TRACE ------
[exception]: Executing test client: I/O error reading reply. I/O error reading reply while executing "[srv $level "client"] {*}$args" (procedure "r" line 7) invoked from within "r del zset" ("uplevel" body line 2) invoked from within "uplevel 1 $code" (procedure "test" line 47) invoked from within "test "SORT sorted set: +inf and -inf handling" { r del zset r zadd zset -100 a r zadd zset 200 b r zadd zset -300 c ..." ("uplevel" body line 163) invoked from within "uplevel 1 $code " (procedure "start_server" line 3) invoked from within "start_server { tags {"sort"} overrides { "list-max-ziplist-size" 32 "set-max-intset-entries" 32 } } { proc create_rand..." (file "tests/unit/sort.tcl" line 1) invoked from within "source $path" (procedure "execute_test_file" line 4) invoked from within "execute_test_file $data" (procedure "test_client_main" line 10) invoked from within "test_client_main $::test_server_port " Killing still running Redis server 18576 verbus@ubuntu-s-4vcpu-8gb-nyc3-01:~/redis-6.0.0$
Comment From: antirez
@verbus thanks @oranagra It looks like that the server already crashed before executing the -inf/+inf test. Like if it was crashed as a result of the EVAL test that passed before the crash. I can't explain why in the original crash report the comandstats don't display things like "ZADD", and there is such short uptime.
Comment From: antirez
@verbus doing the same test with --clients 1 multiple times stops exactly at the same point? Thank you.
Comment From: antirez
@verbus p.s. I want to try to waste less of your time. You can do that:
./runtest --single unit/sort
In this way you will execute just the SORT unit test, and avoid waiting for all the other passing tests.
Comment From: verbus
See below: verbus@ubuntu-s-4vcpu-8gb-nyc3-01:~/redis-6.0.0$ ./runtest --single unit/sort Cleanup: may take some time... OK Starting test server at port 11111
Testing unit/sort
ok: Old Ziplist: SORT BY key
ok: Old Ziplist: SORT BY key with limit
ok: Old Ziplist: SORT BY hash field
ok: Old Linked list: SORT BY key
ok: Old Linked list: SORT BY key with limit
ok: Old Linked list: SORT BY hash field
ok: Old Big Linked list: SORT BY key
ok: Old Big Linked list: SORT BY key with limit
ok: Old Big Linked list: SORT BY hash field
ok: Intset: SORT BY key
ok: Intset: SORT BY key with limit
ok: Intset: SORT BY hash field
ok: Hash table: SORT BY key
ok: Hash table: SORT BY key with limit
ok: Hash table: SORT BY hash field
ok: Big Hash table: SORT BY key
ok: Big Hash table: SORT BY key with limit
ok: Big Hash table: SORT BY hash field
ok: SORT GET #
ok: SORT GET
Logged warnings (pid 26377): (none)
[exception]: Executing test client: I/O error reading reply. I/O error reading reply while executing "[srv $level "client"] {*}$args" (procedure "r" line 7) invoked from within "r set weight_$i $rint" (procedure "create_random_dataset" line 19) invoked from within "create_random_dataset $num lpush" ("uplevel" body line 3) invoked from within "uplevel 1 $code" (procedure "tags" line 3) invoked from within "tags {"slow"} { set num 100 set res [create_random_dataset $num lpush]
test "SORT speed, $num element list BY key, 100 times"..."
("uplevel" body line 260)
invoked from within
"uplevel 1 $code " (procedure "start_server" line 3) invoked from within "start_server { tags {"sort"} overrides { "list-max-ziplist-size" 32 "set-max-intset-entries" 32 } } { proc create_rand..." (file "tests/unit/sort.tcl" line 1) invoked from within "source $path" (procedure "execute_test_file" line 4) invoked from within "execute_test_file $data" (procedure "test_client_main" line 10) invoked from within "test_client_main $::test_server_port " Killing still running Redis server 26377 verbus@ubuntu-s-4vcpu-8gb-nyc3-01:~/redis-6.0.0$
Comment From: verbus
Reproduced on another system:
verbus@sandbox01:~/redis-6.0.0$ ./runtest --single unit/sort Cleanup: may take some time... OK Starting test server at port 11111
Testing unit/sort
ok: Old Ziplist: SORT BY key
ok: Old Ziplist: SORT BY key with limit
ok: Old Ziplist: SORT BY hash field
ok: Old Linked list: SORT BY key
ok: Old Linked list: SORT BY key with limit
ok: Old Linked list: SORT BY hash field
ok: Old Big Linked list: SORT BY key
ok: Old Big Linked list: SORT BY key with limit
ok: Old Big Linked list: SORT BY hash field
ok: Intset: SORT BY key
ok: Intset: SORT BY key with limit
ok: Intset: SORT BY hash field
ok: Hash table: SORT BY key
ok: Hash table: SORT BY key with limit
ok: Hash table: SORT BY hash field
ok: Big Hash table: SORT BY key
ok: Big Hash table: SORT BY key with limit
ok: Big Hash table: SORT BY hash field
ok: SORT GET #
ok: SORT GET
Logged warnings (pid 7315):
=== REDIS BUG REPORT START: Cut & paste starting from here ===
7315:M 01 May 2020 17:45:17.383 # Redis 6.0.0 crashed by signal: 11
7315:M 01 May 2020 17:45:17.383 # Crashed running the instruction at: 0x7f3d58d557d0
7315:M 01 May 2020 17:45:17.383 # Accessing address: 0x557d9017fc68
7315:M 01 May 2020 17:45:17.383 # Failed assertion:
------ STACK TRACE ------ EIP: /lib/x86_64-linux-gnu/libc.so.6(malloc_usable_size+0x40)[0x7f3d58d557d0]
Backtrace: src/redis-server 127.0.0.1:21212(logStackTrace+0x5a)[0x557d8f1d336a] src/redis-server 127.0.0.1:21212(sigsegvHandler+0xb1)[0x557d8f1d3b21] /lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f3d590be890] /lib/x86_64-linux-gnu/libc.so.6(malloc_usable_size+0x40)[0x7f3d58d557d0] src/redis-server 127.0.0.1:21212(+0x42479)[0x557d8f195479] src/redis-server 127.0.0.1:21212(listDelNode+0x37)[0x557d8f183dc7] src/redis-server 127.0.0.1:21212(writeToClient+0x24a)[0x557d8f19b8da] src/redis-server 127.0.0.1:21212(handleClientsWithPendingWrites+0x82)[0x557d8f19ba02] src/redis-server 127.0.0.1:21212(handleClientsWithPendingWritesUsingThreads+0x265)[0x557d8f1a13f5] src/redis-server 127.0.0.1:21212(beforeSleep+0xad)[0x557d8f18a76d] src/redis-server 127.0.0.1:21212(aeMain+0x1e)[0x557d8f1870ee] src/redis-server 127.0.0.1:21212(main+0x52d)[0x557d8f1837bd] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7)[0x7f3d58cdcb97] src/redis-server 127.0.0.1:21212(_start+0x2a)[0x557d8f183a1a]
------ INFO OUTPUT ------
Server
redis_version:6.0.0 redis_git_sha1:00000000 redis_git_dirty:0 redis_build_id:44c4e0aea519fb58 redis_mode:standalone os:Linux 4.15.0-99-generic x86_64 arch_bits:64 multiplexing_api:epoll atomicvar_api:atomic-builtin gcc_version:7.5.0 process_id:7315 run_id:dd25dac7bd11a0bdff0e2a3518675d4ee5dfa920 tcp_port:21212 uptime_in_seconds:8 uptime_in_days:0 hz:10 configured_hz:10 lru_clock:11296813 executable:/home/verbus/redis-6.0.0/src/redis-server config_file:/home/verbus/redis-6.0.0/./tests/tmp/redis.conf.7297.2
Clients
connected_clients:1 client_recent_max_input_buffer:2 client_recent_max_output_buffer:0 blocked_clients:0 tracking_clients:0 clients_in_timeout_table:0
Memory
used_memory:3104400 used_memory_human:2.96M used_memory_rss:9981952 used_memory_rss_human:9.52M used_memory_peak:3761968 used_memory_peak_human:3.59M used_memory_peak_perc:82.52% used_memory_overhead:1955682 used_memory_startup:876128 used_memory_dataset:1148718 used_memory_dataset_perc:51.55% allocator_allocated:3729216 allocator_active:9944064 allocator_resident:9944064 total_system_memory:8363671552 total_system_memory_human:7.79G used_memory_lua:41984 used_memory_lua_human:41.00K used_memory_scripts:264 used_memory_scripts_human:264B number_of_cached_scripts:1 maxmemory:0 maxmemory_human:0B maxmemory_policy:noeviction allocator_frag_ratio:2.67 allocator_frag_bytes:6214848 allocator_rss_ratio:1.00 allocator_rss_bytes:0 rss_overhead_ratio:1.00 rss_overhead_bytes:37888 mem_fragmentation_ratio:2.68 mem_fragmentation_bytes:6252736 mem_not_counted_for_evict:0 mem_replication_backlog:0 mem_clients_slaves:0 mem_clients_normal:16986 mem_aof_buffer:0 mem_allocator:libc active_defrag_running:0 lazyfree_pending_objects:0
Persistence
loading:0 rdb_changes_since_last_save:66210 rdb_bgsave_in_progress:0 rdb_last_save_time:1588355109 rdb_last_bgsave_status:ok rdb_last_bgsave_time_sec:-1 rdb_current_bgsave_time_sec:-1 rdb_last_cow_size:0 aof_enabled:0 aof_rewrite_in_progress:0 aof_rewrite_scheduled:0 aof_last_rewrite_time_sec:-1 aof_current_rewrite_time_sec:-1 aof_last_bgrewrite_status:ok aof_last_write_status:ok aof_last_cow_size:0 module_fork_in_progress:0 module_fork_last_cow_size:0
Stats
total_connections_received:2 total_commands_processed:66269 instantaneous_ops_per_sec:5298 total_net_input_bytes:3218083 total_net_output_bytes:753282 instantaneous_input_kbps:251.78 instantaneous_output_kbps:141.46 rejected_connections:0 sync_full:0 sync_partial_ok:0 sync_partial_err:0 expired_keys:0 expired_stale_perc:0.00 expired_time_cap_reached_count:0 expire_cycle_cpu_milliseconds:0 evicted_keys:0 keyspace_hits:66166 keyspace_misses:0 pubsub_channels:0 pubsub_patterns:0 latest_fork_usec:0 migrate_cached_sockets:0 slave_expires_tracked_keys:0 active_defrag_hits:0 active_defrag_misses:0 active_defrag_key_hits:0 active_defrag_key_misses:0 tracking_total_keys:0 tracking_total_items:0 unexpected_error_replies:0
Replication
role:master connected_slaves:0 master_replid:3fe9964f82ed61b1dedeef81f1423c4b57a6c792 master_replid2:0000000000000000000000000000000000000000 master_repl_offset:0 master_repl_meaningful_offset:0 second_repl_offset:-1 repl_backlog_active:0 repl_backlog_size:1048576 repl_backlog_first_byte_offset:0 repl_backlog_histlen:0
CPU
used_cpu_sys:1.444625 used_cpu_user:0.798557 used_cpu_sys_children:0.000000 used_cpu_user_children:0.000000
Modules
Commandstats
cmdstat_sort:calls=37,usec=58217,usec_per_call=1573.43 cmdstat_multi:calls=1,usec=0,usec_per_call=0.00 cmdstat_eval:calls=1,usec=107,usec_per_call=107.00 cmdstat_get:calls=32,usec=19,usec_per_call=0.59 cmdstat_lpush:calls=11036,usec=30179,usec_per_call=2.73 cmdstat_debug:calls=8,usec=2044,usec_per_call=255.50 cmdstat_ping:calls=1,usec=1,usec_per_call=1.00 cmdstat_llen:calls=2,usec=2,usec_per_call=1.00 cmdstat_command:calls=2,usec=3,usec_per_call=1.50 cmdstat_del:calls=13,usec=3066,usec_per_call=235.85 cmdstat_select:calls=1,usec=2,usec_per_call=2.00 cmdstat_exec:calls=1,usec=9,usec_per_call=9.00 cmdstat_set:calls=22048,usec=63105,usec_per_call=2.86 cmdstat_zadd:calls=20,usec=75,usec_per_call=3.75 cmdstat_sadd:calls=11016,usec=30749,usec_per_call=2.79 cmdstat_lrange:calls=2,usec=7,usec_per_call=3.50 cmdstat_hset:calls=22048,usec=69566,usec_per_call=3.16
Cluster
cluster_enabled:0
Keyspace
db9:keys=20004,expires=0,avg_ttl=0
------ CLIENT LIST OUTPUT ------ id=5 addr=127.0.0.1:38361 fd=8 name= age=7 idle=0 flags=N db=9 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=1 omem=40 events=r cmd=eval user=default
------ REGISTERS ------ 7315:M 01 May 2020 17:45:17.384 # RAX:0000000000000000 RBX:0000557d900def10 RCX:0000557d900def00 RDX:00000000000a0d60 RDI:0000557d900def10 RSI:0000557d8fee4fb0 RBP:0000557d8fce9e00 RSP:00007ffe677b4a48 R8 :0000000000000000 R9 :0000000000000000 R10:0000000000000000 R11:0000000000000000 R12:0000557d8fcee4a8 R13:0000557d900def10 R14:0000000000000027 R15:0000000000000027 RIP:00007f3d58d557d0 EFL:0000000000010246 CSGSFS:002b000000000033 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a57) -> 0000000000000000 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a56) -> 0000557d8fc52aa3 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a55) -> 0000000000000001 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a54) -> 0000557d8f19b960 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a53) -> 00007ffe677b4ad0 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a52) -> 0000557d8fcee250 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a51) -> 0000000000000001 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a50) -> 000000008f19b960 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a4f) -> 0000557d8fc52d70 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a4e) -> 0000557d8f19b8da 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a4d) -> 0000000000000052 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a4c) -> 0000557d8fcee250 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a4b) -> 0000000000000002 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a4a) -> 0000557d8f183dc7 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a49) -> 0000557d8fee4fb0 7315:M 01 May 2020 17:45:17.384 # (00007ffe677b4a48) -> 0000557d8f195479
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------ 7315:M 01 May 2020 17:45:17.384 # Bio thread for job type #0 terminated 7315:M 01 May 2020 17:45:17.385 # Bio thread for job type #1 terminated 7315:M 01 May 2020 17:45:17.385 # Bio thread for job type #2 terminated *** Preparing to test memory region 557d8f49c000 (118784 bytes) *** Preparing to test memory region 557d8fc3c000 (5152768 bytes) *** Preparing to test memory region 7f3d568ac000 (266240 bytes) *** Preparing to test memory region 7f3d568ee000 (8388608 bytes) *** Preparing to test memory region 7f3d570ef000 (8388608 bytes) *** Preparing to test memory region 7f3d578f0000 (8716288 bytes) *** Preparing to test memory region 7f3d58670000 (4096 bytes) *** Preparing to test memory region 7f3d590a8000 (16384 bytes) *** Preparing to test memory region 7f3d592c7000 (16384 bytes) *** Preparing to test memory region 7f3d5954e000 (4096 bytes) *** Preparing to test memory region 7f3d59cf0000 (32768 bytes) *** Preparing to test memory region 7f3d59d1a000 (4096 bytes) .O.O.O.O.O.O.O.O.O.O.O.O Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
------ DUMPING CODE AROUND EIP ------ Symbol: malloc_usable_size (base: 0x7f3d58d55790) Module: /lib/x86_64-linux-gnu/libc.so.6 (base 0x7f3d58cbb000) $ xxd -r -p /tmp/dump.hex /tmp/dump.bin $ objdump --adjust-vma=0x7f3d58d55790 -D -b binary -m i386:x86-64 /tmp/dump.bin
7315:M 01 May 2020 17:45:17.517 # dump of function (hexdump of 192 bytes): 4885ff7453488b57f8488d4ff04889d04883e2f883e002833d5e3135000174404885c0741b483b0d7c3135007222483b0d6b3135007319488d42f8c30f1f4000f64417f801488d4af8480f45c1c36690488d42f0c30f1f0031c0c30f1f4400004989c84889ce48c1ee0b49c1e8034131f0be020000004180f801440f44c64885c00f94c00fb6c0488d44c2ff0fb65407f04438c2742b84d2742c488d72104839f07312eb210f1f0084d2741a488d72104839c677114829d00fb614014438c275
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
Please report the crash by opening an issue on github:
http://github.com/antirez/redis/issues
Suspect RAM error? Use redis-server --test-memory to verify it.
[exception]: Executing test client: I/O error reading reply. I/O error reading reply while executing "[srv $level "client"] {*}$args" (procedure "r" line 7) invoked from within "r del zset" ("uplevel" body line 2) invoked from within "uplevel 1 $code" (procedure "test" line 47) invoked from within "test "SORT sorted set: +inf and -inf handling" { r del zset r zadd zset -100 a r zadd zset 200 b r zadd zset -300 c ..." ("uplevel" body line 163) invoked from within "uplevel 1 $code " (procedure "start_server" line 3) invoked from within "start_server { tags {"sort"} overrides { "list-max-ziplist-size" 32 "set-max-intset-entries" 32 } } { proc create_rand..." (file "tests/unit/sort.tcl" line 1) invoked from within "source $path" (procedure "execute_test_file" line 4) invoked from within "execute_test_file $data" (procedure "test_client_main" line 10) invoked from within "test_client_main $::test_server_port " Killing still running Redis server 7315 verbus@sandbox01:~/redis-6.0.0$
Comment From: oranagra
@verbus is it the exact same binary on both machines? can you back up this binary, try to re-build from scratch (after make distclean) and see if it still reproduces?
Comment From: verbus
Both were just built form source of 6.0.0.
Comment From: oranagra
So these are two independent builds? where they done in a clean checkout or did that folder have an older build?
Comment From: verbus
See below for the build script used on both systems:
# Main body starts here....
#
# cd to home directory
cd ~verbus || { echo "Error----> Cannot change to verbus directory." >&2; exit 2; }
export R="redis-5.0.7"
export R="redis-5.0.8"
export R="redis-5.0.9"
export R="redis-6.0.0"
rm -rf $R
tar -zxvf Downloads/$R.tar.gz
# Move into the Redis directory
cd $R || { echo "Error----> Cannot change to redis directory." >&2; exit 4; }
# Do make distclean
make distclean
# Do make
#time make -j2 MALLOC=libc || { echo "Error----> make failed." >&2; exit 5; }
time make MALLOC=libc || { echo "Error----> make failed." >&2; exit 5; }
# Run the builtin test
time make -j4 test || { echo "Error----> make test failed." >&2; exit 6; }
echo
echo "All went well"
exit 0
Comment From: antirez
Oh, it's a libc malloc build. Let's try if this triggers the error for us as well.
Comment From: antirez
Ok now I can reproduce it. Only happens with the libc malloc. Now we can fix it, thank you @verbus.
Comment From: antirez
@oranagra it's fb732f7a944a4d4c90bb7375cb6030e88211f5aa, for now I'll just revert and release 6.0.1, anyway the fix was not urgent. Later we can work in a more relaxed way to implement it without this issue. Ok that was simpler than expected after all...
Comment From: antirez
6.0.1 is out with the bug fixed :-) Thank you @verbus!
Comment From: verbus
Main body starts here....
cd to home directory
cd ~verbus || { echo "Error----> Cannot change to verbus directory." >&2; exit 2; }
export R="redis-5.0.7" export R="redis-5.0.8" export R="redis-5.0.9" export R="redis-6.0.0" export R="redis-6.0.1"
rm -rf $R
tar -zxvf Downloads/$R.tar.gz
tar -xvf Downloads/$R.tar # <<<<<< NOTICE the change from ^
Move into the Redis directory
cd $R || { echo "Error----> Cannot change to redis directory." >&2; exit 4; }
Do make distclean
make distclean
Do make
time make -j2 MALLOC=libc ||
time make MALLOC=libc || { echo "Error----> make failed." >&2; exit 5; }
Run the builtin test
time make -j4 test || { echo "Error----> make test failed." >&2; exit 6; }
52/53 done]: integration/replication (203 seconds) ok: Slave should be able to synchronize with the master ok: Detect write load to master ok: Test replication partial resync: backlog expired (diskless: yes, swapdb, reconnect: 1)
Testing solo test
The End
Execution time of different units: 0 seconds - unit/type/incr 0 seconds - unit/printver 0 seconds - unit/auth 1 seconds - unit/keyspace 2 seconds - unit/protocol 0 seconds - unit/quit 3 seconds - unit/multi 1 seconds - unit/acl 5 seconds - unit/type/stream-cgroups 8 seconds - unit/type/hash 10 seconds - unit/type/set 11 seconds - unit/type/list 12 seconds - unit/scan 12 seconds - unit/other 14 seconds - unit/type/string 14 seconds - unit/sort 15 seconds - unit/expire 1 seconds - integration/logging 2 seconds - integration/convert-zipmap-hash-on-load 17 seconds - unit/type/zset 4 seconds - integration/rdb 1 seconds - unit/pubsub 2 seconds - unit/slowlog 11 seconds - integration/aof 8 seconds - integration/psync2-pingoff 26 seconds - unit/type/list-2 1 seconds - unit/introspection 2 seconds - unit/limits 9 seconds - unit/scripting 6 seconds - unit/introspection-2 27 seconds - integration/block-repl 26 seconds - integration/replication-2 6 seconds - unit/bitops 6 seconds - unit/bitfield 24 seconds - integration/psync2-reg 2 seconds - unit/lazyfree 41 seconds - unit/dump 1 seconds - unit/tls 11 seconds - unit/memefficiency 7 seconds - unit/wait 52 seconds - unit/type/stream 38 seconds - integration/psync2 15 seconds - unit/pendingquerybuf 51 seconds - integration/replication-4 56 seconds - integration/replication-3 79 seconds - unit/aofrw 50 seconds - unit/geo 65 seconds - unit/hyperloglog 76 seconds - unit/obuf-limits 81 seconds - unit/maxmemory 105 seconds - unit/type/list-3 203 seconds - integration/replication 214 seconds - integration/replication-psync 0 seconds - defrag
\o/ All tests passed without errors!
Cleanup: may take some time... OK make[1]: Leaving directory '/home/verbus/redis-6.0.1/src'
real 3m48.681s user 0m1.678s sys 0m1.019s
Thanks! to all !!!
Comment From: antirez
Thank you for your help!
On Sat, May 2, 2020, 01:44 Verbus Counts notifications@github.com wrote:
Main body starts here.... cd to home directory
cd ~verbus || { echo "Error----> Cannot change to verbus directory." >&2; exit 2; }
export R="redis-5.0.7" export R="redis-5.0.8" export R="redis-5.0.9" export R="redis-6.0.0" export R="redis-6.0.1"
rm -rf $R
tar -zxvf Downloads/$R.tar.gz
tar -xvf Downloads/$R.tar # <<<<<< NOTICE the change from ^ Move into the Redis directory
cd $R || { echo "Error----> Cannot change to redis directory." >&2; exit 4; } Do make distclean
make distclean Do make
time make -j2 MALLOC=libc || { echo "Error----> make failed." >&2; exit
5; } time make MALLOC=libc || { echo "Error----> make failed." >&2; exit 5; } Run the builtin test
time make -j4 test ||
52/53 done]: integration/replication (203 seconds) ok: Slave should be able to synchronize with the master ok: Detect write load to master ok: Test replication partial resync: backlog expired (diskless: yes, swapdb, reconnect: 1)
Testing solo test
The EndExecution time of different units: 0 seconds - unit/type/incr 0 seconds - unit/printver 0 seconds - unit/auth 1 seconds - unit/keyspace 2 seconds - unit/protocol 0 seconds - unit/quit 3 seconds - unit/multi 1 seconds - unit/acl 5 seconds - unit/type/stream-cgroups 8 seconds - unit/type/hash 10 seconds - unit/type/set 11 seconds - unit/type/list 12 seconds - unit/scan 12 seconds - unit/other 14 seconds - unit/type/string 14 seconds - unit/sort 15 seconds - unit/expire 1 seconds - integration/logging 2 seconds - integration/convert-zipmap-hash-on-load 17 seconds - unit/type/zset 4 seconds - integration/rdb 1 seconds - unit/pubsub 2 seconds - unit/slowlog 11 seconds - integration/aof 8 seconds - integration/psync2-pingoff 26 seconds - unit/type/list-2 1 seconds - unit/introspection 2 seconds - unit/limits 9 seconds - unit/scripting 6 seconds - unit/introspection-2 27 seconds - integration/block-repl 26 seconds - integration/replication-2 6 seconds - unit/bitops 6 seconds - unit/bitfield 24 seconds - integration/psync2-reg 2 seconds - unit/lazyfree 41 seconds - unit/dump 1 seconds - unit/tls 11 seconds - unit/memefficiency 7 seconds - unit/wait 52 seconds - unit/type/stream 38 seconds - integration/psync2 15 seconds - unit/pendingquerybuf 51 seconds - integration/replication-4 56 seconds - integration/replication-3 79 seconds - unit/aofrw 50 seconds - unit/geo 65 seconds - unit/hyperloglog 76 seconds - unit/obuf-limits 81 seconds - unit/maxmemory 105 seconds - unit/type/list-3 203 seconds - integration/replication 214 seconds - integration/replication-psync 0 seconds - defrag
\o/ All tests passed without errors!
Cleanup: may take some time... OK make[1]: Leaving directory '/home/verbus/redis-6.0.1/src'
real 3m48.681s user 0m1.678s sys 0m1.019s
Thanks! to all !!!
— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/antirez/redis/issues/7169#issuecomment-622612974, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAQAYGLINILNVX5LBDQHVDRPNNG3ANCNFSM4MXFA4ZA .