search

basho / riak

Riak is a decentralized datastore from Basho Technologies.
http://docs.basho.com
Apache License 2.0
3.93k stars 534 forks source link

Format error hash tree #1004

Closed sAws closed 4 years ago

sAws commented 4 years ago

Hello I install riak 2.9.0p5 Data not created Use log.console.level = debug And i see this error: 2020-02-11 17:57:10.361 [debug] <0.27846.1>@hashtree:compare:1169 FORMAT ERROR: "Tree ~p level ~p bucket ~p\nL=~p\nR=~p\nD=\n" [{state,<<252,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,3>>,1438665674247607560106752257205091097473808596992,3,1048576,1024,0,{dict,0,16,16,8,80,48,{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]}}},<<>>,"/var/lib/riak/yz_anti_entropy/1438665674247607560106752257205091097473808596992",<<>>,incremental,[],0,{array,38837,0,0,100000}},1,0,[],[],[]]

uname -a
Linux riak-1 4.4.0-131-generic #157-Ubuntu SMP Thu Jul 12 15:51:36 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 16.04.5 LTS
Release:    16.04
Codename:   xenial

Full settings:

log.console = file
log.console.level = debug
log.console.file = $(platform_log_dir)/console.log
log.error.file = $(platform_log_dir)/error.log
log.syslog = off
log.crash = on
log.crash.file = $(platform_log_dir)/crash.log
log.crash.maximum_message_size = 64KB
log.crash.size = 10MB
log.crash.rotation = $D0
log.crash.rotation.keep = 5
nodename = riak@riak1.local
distributed_cookie = riak
erlang.async_threads = 64
erlang.max_ports = 262144
dtrace = off
platform_bin_dir = /usr/sbin
platform_data_dir = /var/lib/riak
platform_etc_dir = /etc/riak
platform_lib_dir = /usr/lib/riak/lib
platform_log_dir = /var/log/riak
listener.http.internal = 192.168.65.45:8098
listener.protobuf.internal = 192.168.65.45:8087
anti_entropy = active
tictacaae_active = passive
tictacaae_dataroot = $(platform_data_dir)/tictac_aae
tictacaae_rebuildwait = 336
tictacaae_rebuilddelay = 345600
node_worker_pool_size = 2
af1_worker_pool_size = 1
af2_worker_pool_size = 1
af3_worker_pool_size = 2
af4_worker_pool_size = 1
be_worker_pool_size = 1
storage_backend = multi
object.format = 1
object.size.warning_threshold = 5MB
object.size.maximum = 50MB
object.siblings.warning_threshold = 25
object.siblings.maximum = 100
bitcask.data_root = $(platform_data_dir)/bitcask
bitcask.io_mode = erlang
riak_control = on
riak_control.auth.mode = off
leveldb.maximum_memory.percent = 70
leveldb.compression = on
leveldb.compression.algorithm = lz4
leveled.data_root = $(platform_data_dir)/leveled
leveled.sync_strategy = none
leveled.compression_method = native
leveled.compression_point = on_receipt
leveled.log_level = info
leveled.journal_size = 1000000000
leveled.journal_objectcount = 200000
leveled.ledger_pagecachelevel = 4
leveled.compaction_runs_perday = 24
leveled.compaction_low_hour = 0
leveled.compaction_top_hour = 23
leveled.max_run_length = 4
multi_backend.leveldb_backend.storage_backend = leveldb
multi_backend.default = leveldb_backend
multi_backend.leveldb_backend.leveled.journal_size = 1000000000
multi_backend.leveldb_backend.leveled.journal_objectcount = 200000
multi_backend.leveldb_backend.leveled.ledger_pagecachelevel = 4
search = on
search.solr.start_timeout = 30s
search.solr.port = 8093
search.solr.jmx_port = 8985
search.solr.jvm_options = -d64 -Xms256m -Xmx256m -XX:+UseCompressedOops
erlang.K = on
erlang.W = w
erlang.max_ets_tables = 256000
erlang.smp = enable
erlang.distribution_buffer_size = 131072  # in KB / default = 32MB
erlang.process_limit = 256000
erlang.crash_dump = /var/log/riak/erl_crash.dump
erlang.fullsweep_after = 0
ssl.certfile = $(platform_etc_dir)/cert.pem
ssl.cacertfile = $(platform_etc_dir)/cert.pem
ssl.keyfile = $(platform_etc_dir)/cert.pem
# custom
buckets.default.n_val = 3
buckets.default.r = quorum
buckets.default.w = quorum
buckets.default.dw = quorum
buckets.default.rw = all # default quorum
buckets.default.pw = 1 # default 0
buckets.default.pr = 1 # default 0
buckets.default.allow_mult = false
buckets.default.last_write_wins = true # default false
handoff.port = 8099
anti_entropy.tree.build_limit.per_timespan = 1000h # default 1h
anti_entropy.tree.build_limit.number = 1
anti_entropy.tree.expiry = 1000w # default 1w
anti_entropy.max_open_files = 20
anti_entropy.write_buffer_size = 4194304 # default 4MB
riak_control.auth.mode = userlist
riak_control.auth.user.dev.password = dev
sasl = off

Full logs:

A=[]
B=[]
D=[]
2020-02-11 17:56:59.050 [debug] <0.365.0>@riak_kv_entropy_manager:maybe_clear_exchange:609 Untracking exchange: 1164634117248063262943561351070788031288321245184 :: normal
2020-02-11 17:57:10.359 [debug] <0.27838.1>@yz_exchange_fsm:init:87 Starting exchange between KV and Yokozuna: 1438665674247607560106752257205091097473808596992
2020-02-11 17:57:10.359 [debug] <0.3846.1>@riak_kv_index_hashtree:handle_call:344 Updating tree: (vnode)=1438665674247607560106752257205091097473808596992 (preflist)={1438665674247607560106752257205091097473808596992,3}
2020-02-11 17:57:10.359 [debug] <0.2065.0>@yz_solrq_drain_mgr:handle_call:82 Solrq drain starting for partition 1438665674247607560106752257205091097473808596992
2020-02-11 17:57:10.360 [debug] <0.2064.0> Supervisor yz_solrq_sup started yz_solrq_drain_fsm:start_link([{owner_pid,<0.27841.1>},{exchange_fsm_pid,<0.27838.1>},{yz_index_hashtree_update_params,{<0.2777.0>,...}},...]) at pid <0.27842.1>
2020-02-11 17:57:10.360 [debug] <0.27842.1>@yz_solrq_drain_fsm:prepare:165 Solrq drain starting for partition 1438665674247607560106752257205091097473808596992
2020-02-11 17:57:10.360 [debug] <0.27842.1>@yz_solrq_drain_fsm:wait_for_drain_complete:186 Solrq drain completed for all workers for partition 1438665674247607560106752257205091097473808596992.  Resuming batching.
2020-02-11 17:57:10.360 [debug] <0.2777.0>@yz_index_hashtree:handle_call:223 Updating tree for partition 1438665674247607560106752257205091097473808596992 preflist {1438665674247607560106752257205091097473808596992,3}
2020-02-11 17:57:10.360 [debug] <0.27838.1>@yz_exchange_fsm:update_trees:176 Tree yz_index_hashtree built; staying in update_trees state
2020-02-11 17:57:10.360 [debug] <0.27841.1>@yz_solrq_drain_mgr:wait_for_workers_resumed_or_crash:163 Workers resumed.
2020-02-11 17:57:10.361 [debug] <0.27841.1>@yz_solrq_drain_mgr:wait_for_exit:179 Drain <0.27842.1> completed normally.
2020-02-11 17:57:10.361 [debug] <0.27841.1>@yz_solrq_drain_mgr:handle_call:96 Solrq drain about to send compelte message for partition 1438665674247607560106752257205091097473808596992.
2020-02-11 17:57:10.361 [debug] <0.2065.0>@yz_solrq_drain_mgr:handle_cast:105 Solrq drain completed for partition 1438665674247607560106752257205091097473808596992.
2020-02-11 17:57:10.361 [debug] <0.27838.1>@yz_exchange_fsm:update_trees:173 Tree riak_kv_index_hashtree built; Moving to key exchange
2020-02-11 17:57:10.361 [debug] <0.27838.1>@yz_exchange_fsm:key_exchange:184 Starting key exchange for partition 1438665674247607560106752257205091097473808596992 preflist {1438665674247607560106752257205091097473808596992,3}
2020-02-11 17:57:10.361 [debug] <0.27846.1>@hashtree:compare:1169 FORMAT ERROR: "Tree ~p level ~p bucket ~p\nL=~p\nR=~p\nD=\n" [{state,<<252,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,3>>,1438665674247607560106752257205091097473808596992,3,1048576,1024,0,{dict,0,16,16,8,80,48,{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]}}},<<>>,"/var/lib/riak/yz_anti_entropy/1438665674247607560106752257205091097473808596992",<<>>,incremental,[],0,{array,38837,0,0,100000}},1,0,[],[],[]]
2020-02-11 17:57:10.361 [debug] <0.2260.0>@yz_entropy_mgr:maybe_clear_exchange:454 Untracking exchange: 1438665674247607560106752257205091097473808596992 :: normal
2020-02-11 17:57:14.043 [debug] <0.27869.1>@riak_kv_exchange_fsm:init:80 Starting exchange: {1164634117248063262943561351070788031288321245184,'riak@riak1.local'}
2020-02-11 17:57:14.044 [info] <0.365.0>@riak_kv_entropy_manager:maybe_exchange:986 Attempt to start exchange between {1164634117248063262943561351070788031288321245184,3} and 1210306043414653979137426502093171875652569137152 resulted in ok
2020-02-11 17:57:14.044 [debug] <0.27869.1>@riak_kv_exchange_fsm:update_trees:151 Sending to {1164634117248063262943561351070788031288321245184,'riak@riak1.local'}
2020-02-11 17:57:14.044 [debug] <0.27869.1>@riak_kv_exchange_fsm:update_trees:152 Sending to {1210306043414653979137426502093171875652569137152,'riak@riak1.local'}
2020-02-11 17:57:14.045 [debug] <0.2980.1>@riak_kv_index_hashtree:handle_call:344 Updating tree: (vnode)=1164634117248063262943561351070788031288321245184 (preflist)={1164634117248063262943561351070788031288321245184,3}
2020-02-11 17:57:14.045 [debug] <0.3116.1>@riak_kv_index_hashtree:handle_call:344 Updating tree: (vnode)=1210306043414653979137426502093171875652569137152 (preflist)={1164634117248063262943561351070788031288321245184,3}
2020-02-11 17:57:14.045 [debug] <0.27869.1>@riak_kv_exchange_fsm:update_trees:166 Moving to key exchange
2020-02-11 17:57:14.045 [debug] <0.27869.1>@riak_kv_exchange_fsm:key_exchange:179 Starting key exchange between {1164634117248063262943561351070788031288321245184,'riak@riak1.local'} and {1210306043414653979137426502093171875652569137152,'riak@riak1.local'}
2020-02-11 17:57:14.045 [debug] <0.27869.1>@riak_kv_exchange_fsm:key_exchange:180 Exchanging hashes for preflist {1164634117248063262943561351070788031288321245184,3}
2020-02-11 17:57:14.047 [debug] <0.27876.1>@hashtree:exchange_level:1132 Exchange Level 1 Bucket 0
A=[]
B=[]
D=[]
martinsumner commented 4 years ago

There is an incorrectly formatted debug log

https://github.com/basho/riak_core/blob/develop-2.9/src/hashtree.erl#L1169-L1170

5 ~p's but 6 items in the list. This will only have an impact when running in debug

Do things work as expected with log.console.level = info.

I will look to fix the log in 2.9.1 (which is on the point of being released).

martinsumner commented 4 years ago

https://github.com/basho/riak/tree/riak-2.9.1 includes this fix