Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ElasticSearch with test-6.0.2 #2549

Closed
1 of 7 tasks
sschiessl-bcp opened this issue Dec 11, 2021 · 12 comments · Fixed by #2553
Closed
1 of 7 tasks

ElasticSearch with test-6.0.2 #2549

sschiessl-bcp opened this issue Dec 11, 2021 · 12 comments · Fixed by #2553

Comments

@sschiessl-bcp
Copy link

Bug Description
ES fails to sync with bitshares/bitshares-core:test-6.0.2 and

blockchain_plugins:
 - elasticsearch
 - es_objects
blockchain_args: >
    --replay
    --ignore-api-helper-indexes-warning
    --elasticsearch-start-es-after-block=51150525
    --es-objects-start-es-after-block=51150525
    --es-objects-keep-only-current=true
    --elasticsearch-operation-object=true
    --elasticsearch-operation-string=false
    --elasticsearch-index-prefix=testnet-
    --es-objects-index-prefix=testnet-objects-

The error is

1583954ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166396376"}} 
1583954ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"account_history":{"id":"2.9.166396376","account":"1.2.25983","operation_id":"1.11.84519114","sequence":3554082,"next":"2.9.166396374"},"operation_history":{"trx_in_block":4,"op_in_trx":4,"operation_result":"[0,{}]","virtual_op":0,"op":"","op_object":{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","extensions":[],"amount_":{"amount":1,"asset_id":"1.3.0"}}},"operation_type":0,"operation_id_num":84519114,"block_data":{"block_num":51517550,"block_time":"2021-11-08T18:19:18","trx_id":"5de88b52fbb630ae9cb3e45e0d78b1d62c0daf7d"}} 
1583954ms th_a       elasticsearch_plugin.cpp:193  update_account_histo ] Error adding data to Elastic Search: block num 51517626, account 1.2.25661, data {"id":"1.11.84521613","op":[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],"result":[0,{}],"block_num":51517626,"trx_in_block":4,"op_in_trx":3,"virtual_op":0}
1583969ms th_a       db_notify.cpp:572             notify_applied_block ] Caught plugin exception: 3100000 plugin_exception: plugin exception
Error populating ES database, we are going to keep trying.
    {}
    th_a  elasticsearch_plugin.cpp:543 operator()
1583970ms th_a       db_block.cpp:222              _push_block          ] Failed to push new block:
3100000 plugin_exception: plugin exception
Error populating ES database, we are going to keep trying.
    {}
    th_a  elasticsearch_plugin.cpp:543 operator()

    {"next_block.block_num()":51517626}
    th_a  db_block.cpp:669 _apply_block
1583971ms th_a       db_management.cpp:227         open                 ] 3100000 plugin_exception: plugin exception
Error populating ES database, we are going to keep trying.
    {}
    th_a  elasticsearch_plugin.cpp:543 operator()

    {"next_block.block_num()":51517626}
    th_a  db_block.cpp:669 _apply_block

    {"new_block":{"previous":"031218b9a0f9e9fed7b08d8950563ee13df9f9d9","timestamp":"2021-11-08T18:23:15","witness":"1.6.2","transaction_merkle_root":"a49bdb7d7e62b1f1aaa0d8ccf9007e46ad83119b","extensions":[],"witness_signature":"1f34cba655058b85632de7830d96a2ae0e6a9dea20301e64b10b5d54512388c54e71e45bb98c73739f168edc105f12419d4a5940ff6c2df872a1cb63e99fa37f9b","transactions":[{"ref_block_num":6317,"ref_block_prefix":3855047144,"expiration":"2021-11-08T18:23:40","operations":[[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25957","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}]],"extensions":[],"signatures":["1f577d48c338eec736ea73b197b47dd77cd9695d5e0c92d42784202e027775701976192148b806c5457e308a2bbeabd8aacd4c93970a1674db5f4da6edada1f2e1"],"operation_results":[]},{"ref_block_num":6317,"ref_block_prefix":3855047144,"expiration":"2021-11-08T18:23:41","operations":[[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25957","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}]],"extensions":[],"signatures":["204e9114cf31b6c329bef053c11d2305079ccd0fcb811216b0cf1dfc8c52a7b40f0a7a72dd6f063cdeeecf9cb021cc9ac0bb513bc6dc2bfd4c260114e8fd01f061"],"operation_results":[]},{"ref_block_num":6317,"ref_block_prefix":3855047144,"expiration":"2021-11-08T18:23:41","operations":[[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}]],"extensions":[],"signatures":["1f18d7bf9d91392e9de53de2d4da4e7e55b496bd41539deccb67dc4a2e9a11b2a23dfd406ac72bfdf0c5ca159d7bb026d66a79bb336a4d873183587bae54b89bd3"],"operation_results":[]},{"ref_block_num":6317,"ref_block_prefix":3855047144,"expiration":"2021-11-08T18:23:42","operations":[[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25957","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}]],"extensions":[],"signatures":["1f667fd420f8f0986e73d27daf2e4946f30ba0f79acd502f8d9fc2d89eca429f1b5db90d1d3462744ca072ffebf44032e568b1dd73716a43c586305d9f482104d4"],"operation_results":[]},{"ref_block_num":6317,"ref_block_prefix":3855047144,"expiration":"2021-11-08T18:23:42","operations":[[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}]],"extensions":[],"signatures":["1f106d79e2d6923c52e7527487eec17b3534d4394dd351662ac8cf94cacbe15ba417f16c8e4f20db7de986e8e6c070fb2bce100c3e44de1ad5758e8803b7b86ed9"],"operation_results":[]},{"ref_block_num":6317,"ref_block_prefix":3855047144,"expiration":"2021-11-08T18:23:43","operations":[[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25957","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}]],"extensions":[],"signatures":["1f72b1ce5f0638609896d396aa2de16814c56bf4333f801ea1329c2127b3f0ca715cdf49bbf259adadf94529b4212e0c1fda435f14de8f2f18c81c2f767548bcd1"],"operation_results":[]}]}}
    th_a  db_block.cpp:228 _push_block

    {"data_dir":"/var/lib/bitshares/blockchain"}
    th_a  db_management.cpp:163 reindex
1583971ms th_a       db_management.cpp:227         open                 ] data_dir: /var/lib/bitshares/blockchain 
1583981ms th_a       application.cpp:551           open_chain_database  ] Caught exception 3100000 plugin_exception: plugin exception
Error populating ES database, we are going to keep trying.

Impacts
Describe which portion(s) of BitShares Core may be impacted by this bug. Please tick at least one box.

  • ES

Steps To Reproduce
Steps to reproduce the behavior (example outlined below):
Try syncing ES

Expected Behavior
Syncing works

CORE TEAM TASK LIST

  • Evaluate / Prioritize Bug Report
  • Refine User Stories / Requirements
  • Define Test Cases
  • Design / Develop Solution
  • Perform QA/Testing
  • Update Documentation
@sschiessl-bcp
Copy link
Author

sschiessl-bcp commented Dec 11, 2021

Mainnet feeder is running version 6 as well, so far no issue.

@abitmore
Copy link
Member

@sschiessl-bcp there should be more log messages about the error before the lines you pasted here. Can you please check?

@sschiessl-bcp
Copy link
Author

testnet-2021-11","_type":"data","_id":"2.9.166401363","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125333,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401364","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125334,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401365","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125335,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401366","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125336,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401367","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125337,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401368","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125338,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401369","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125339,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401370","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125340,"_primary_term":1,"status":200}},{"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166401371","_version":584,"result":"updated","_shards":{"total":2,"successful":1,"failed":0},"_seq_no":4786125341,"_primary_term":1,"status":200}}]}
802929ms th_a       elasticsearch_plugin.cpp:334  add_elasticsearch    ] Error sending 10000 lines of bulk data to Elastic Search, the first lines are:
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166396372"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"account_history":{"id":"2.9.166396372","account":"1.2.25983","operation_id":"1.11.84519112","sequence":3554080,"next":"2.9.166396370"},"operation_history":{"trx_in_block":4,"op_in_trx":2,"operation_result":"[0,{}]","virtual_op":0,"op":"","op_object":{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","extensions":[],"amount_":{"amount":1,"asset_id":"1.3.0"}}},"operation_type":0,"operation_id_num":84519112,"block_data":{"block_num":51517550,"block_time":"2021-11-08T18:19:18","trx_id":"5de88b52fbb630ae9cb3e45e0d78b1d62c0daf7d"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166396373"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"account_history":{"id":"2.9.166396373","account":"1.2.25661","operation_id":"1.11.84519113","sequence":40747492,"next":"2.9.166396371"},"operation_history":{"trx_in_block":4,"op_in_trx":3,"operation_result":"[0,{}]","virtual_op":0,"op":"","op_object":{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","extensions":[],"amount_":{"amount":1,"asset_id":"1.3.0"}}},"operation_type":0,"operation_id_num":84519113,"block_data":{"block_num":51517550,"block_time":"2021-11-08T18:19:18","trx_id":"5de88b52fbb630ae9cb3e45e0d78b1d62c0daf7d"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166396374"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"account_history":{"id":"2.9.166396374","account":"1.2.25983","operation_id":"1.11.84519113","sequence":3554081,"next":"2.9.166396372"},"operation_history":{"trx_in_block":4,"op_in_trx":3,"operation_result":"[0,{}]","virtual_op":0,"op":"","op_object":{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","extensions":[],"amount_":{"amount":1,"asset_id":"1.3.0"}}},"operation_type":0,"operation_id_num":84519113,"block_data":{"block_num":51517550,"block_time":"2021-11-08T18:19:18","trx_id":"5de88b52fbb630ae9cb3e45e0d78b1d62c0daf7d"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166396375"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"account_history":{"id":"2.9.166396375","account":"1.2.25661","operation_id":"1.11.84519114","sequence":40747493,"next":"2.9.166396373"},"operation_history":{"trx_in_block":4,"op_in_trx":4,"operation_result":"[0,{}]","virtual_op":0,"op":"","op_object":{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","extensions":[],"amount_":{"amount":1,"asset_id":"1.3.0"}}},"operation_type":0,"operation_id_num":84519114,"block_data":{"block_num":51517550,"block_time":"2021-11-08T18:19:18","trx_id":"5de88b52fbb630ae9cb3e45e0d78b1d62c0daf7d"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"index":{"_index":"testnet-2021-11","_type":"data","_id":"2.9.166396376"}} 
802929ms th_a       elasticsearch_plugin.cpp:338  add_elasticsearch    ] es.bulk_lines[i]: {"account_history":{"id":"2.9.166396376","account":"1.2.25983","operation_id":"1.11.84519114","sequence":3554082,"next":"2.9.166396374"},"operation_history":{"trx_in_block":4,"op_in_trx":4,"operation_result":"[0,{}]","virtual_op":0,"op":"","op_object":{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","extensions":[],"amount_":{"amount":1,"asset_id":"1.3.0"}}},"operation_type":0,"operation_id_num":84519114,"block_data":{"block_num":51517550,"block_time":"2021-11-08T18:19:18","trx_id":"5de88b52fbb630ae9cb3e45e0d78b1d62c0daf7d"}} 
802929ms th_a       elasticsearch_plugin.cpp:193  update_account_histo ] Error adding data to Elastic Search: block num 51517626, account 1.2.25661, data {"id":"1.11.84521613","op":[0,{"fee":{"amount":100,"asset_id":"1.3.0"},"from":"1.2.25983","to":"1.2.25661","amount":{"amount":1,"asset_id":"1.3.0"},"extensions":[]}],"result":[0,{}],"block_num":51517626,"trx_in_block":4,"op_in_trx":3,"virtual_op":0}
802940ms th_a       db_notify.cpp:572             notify_applied_block ] Caught plugin exception: 3100000 plugin_exception: plugin exception
Error populating ES database, we are going to keep trying.
    {}
    th_a  elasticsearch_plugin.cpp:543 operator()
802941ms th_a       db_block.cpp:222              _push_block          ] Failed to push new block:
3100000 plugin_exception: plugin exception
Error populating ES database, we are going to keep trying.
    {}
    th_a  elasticsearch_plugin.cpp:543 operator()

    {"next_block.block_num()":51517626}
    th_a  db_block.cpp:669 _apply_block
802942ms th_a       db_management.cpp:227         open                 ] 3100000 plugin_exception: plugin exception

@abitmore
Copy link
Member

The log messages are still truncated. There may be an error among the 10000 lines of bulk data.
BTW I have synced a testnet ES node without trouble. But I didn't enable es_objects plugin. I re-enabled it and it's replaying.

@abitmore
Copy link
Member

OK I caught that error on my node. Will look into it.

@abitmore
Copy link
Member

Here is the error message:

{"index":{"_index":"btstesthis-2021-11","_type":"data","_id":"2.9.166398662","status":400,"error":{"type":"illegal_argument_exception","reason":"mapper [operation_history.op_object.acceptable_collateral] cannot be
changed from type [text] to [ObjectMapper]"}}}

@abitmore
Copy link
Member

FWIW the error message was found in default.log.

@abitmore
Copy link
Member

abitmore commented Dec 12, 2021

It was explained here: #1396 (comment), In ES,

... all values in the array must be of the same datatype ...

But the data to process now is like this

"acceptable_collateral":[["1.3.1515",{"base":{"amount":10000000,"asset_id":"1.3.0"},"quote":{"amount":4000000,"asset_id":"1.3.1515"}}],["1.3.1516",{"base":{"amount":100000,"asset_id":"1.3.0"},"quote":{"amount":3000,"asset_id":"1.3.1516"}}]],
"acceptable_borrowers":[["1.2.0",5000000],["1.2.6",8000000]],"extensions":[]}]],

By the way, it is strange that the error didn't pop up on the first sync, but popped up on replay. (UPDATE: see #2693 and #2493)

@abitmore abitmore added this to the 6.0.1 - Bugfix release milestone Dec 12, 2021
@sschiessl-bcp
Copy link
Author

Thanks for the investigation. Do you have an idea how to fix it?

@abitmore
Copy link
Member

@sschiessl-bcp Yes, I'm working on a fix.

@abitmore
Copy link
Member

Actually I had anticipated this issue (see #2554) but forgot to re-check or fix.

Anyway now I expect that #2553 will fix it.

@abitmore
Copy link
Member

Fixed by #2553.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants