Using haf_api_node, hivemind block processor died on 'docker compose up` after prev shutdown (was in massive sync at shutdown time), probably C-locale test related
This could be some side-effact of tested software: I was using version that creates database with "C-locale". I will try to dup the issue later after the system is freed up. I have a snapshot of the original conditions, but need to finish long running test of hafbe first.
syncad@steem-14:/haf-pool/syncad/haf_api_node$ docker logs haf-world-hivemind-block-processing-1
[Entrypoint] 2023-12-13 00:23:33,878+00:00 INFO [global] (main) Hivemind arguments: --database-url=postgresql://hivemind@haf/haf_block_log sync
[Entrypoint] 2023-12-13 00:23:33,878+00:00 INFO [global] (main) Hivemind arguments: sync
[Entrypoint] 2023-12-13 00:23:33,879+00:00 INFO [global] (main) Using PostgreSQL instance: postgresql://hivemind@haf/haf_block_log
[Entrypoint] 2023-12-13 00:23:33,881+00:00 INFO [run_hive] (main) Starting Hivemind...
INFO - hive.conf:212 - The database instance is created...
INFO - hive.db.adapter:48 - A database offers maximum connections: 100. Required 15 connections.
INFO - hive.db.adapter:90 - Closing database connection: 'root'
INFO - hive.db.adapter:108 - Disposing SQL engine
INFO - hive.conf:261 - The database is disconnected...
INFO - hive.conf:212 - The database instance is created...
INFO - hive.indexer.sync:52 - Entering HAF mode synchronization
INFO - hive.db.db_state:44 - [MASSIVE] Welcome to hive!
INFO - hive.db.db_state:55 - [MASSIVE] Continue with massive sync...
INFO - hive.indexer.sync:67 - hivemind_version : 2.0.0dev1
INFO - hive.indexer.sync:68 - hivemind_git_rev : c8a8ec7aac1c45e243fbaa6befa93c626cbb78bc
INFO - hive.indexer.sync:69 - hivemind_git_date : 2023-11-08 22:44:15
INFO - hive.indexer.sync:71 - database_schema_version : 34
INFO - hive.indexer.sync:72 - database_patch_date : 2023-12-12 02:44:03.345787
INFO - hive.indexer.sync:73 - database_patched_to_revision : 9d2cc15bea71a39139abdf49569e0eac6dd0b970
INFO - hive.indexer.sync:75 - last_block_from_view : 492000
INFO - hive.indexer.sync:76 - last_imported_block : 492000
INFO - hive.indexer.sync:77 - last_completed_block : 1
INFO - hive.indexer.hive_db.haf_functions:34 - Context already attached - attaching skipped.
INFO - hive.indexer.sync:89 - Using HAF database as block data provider, pointed by url: 'postgresql://hivemind@haf/haf_block_log'
INFO - hive.indexer.sync:99 - Last imported block is: 492000
INFO - hive.indexer.sync:186 - Querying for next block for app context...
INFO - hive.indexer.sync:188 - Next block range from hive.app_next_block is: <None:None>
INFO - hive.indexer.sync:99 - Last imported block is: 492000
INFO - hive.indexer.sync:186 - Querying for next block for app context...
INFO - hive.indexer.sync:188 - Next block range from hive.app_next_block is: <492001:80973941>
INFO - hive.indexer.sync:117 - target_head_block: 80973941
INFO - hive.indexer.sync:118 - test_max_block: None
INFO - hive.indexer.sync:122 - [MASSIVE] *** MASSIVE blocks processing ***
INFO - hive.db.db_state:274 - Dropping foreign keys
INFO - hive.db.db_state:280 - Dropped foreign keys: 0.0189 s
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_reputation_data
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_posts
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_votes
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_follows
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_reblogs
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_feed_cache
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_posts_api_helper
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_communities
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_subscriptions
INFO - hive.db.db_state:202 - [MASSIVE] Begin pre-massive sync hooks for table hive_notification_cache
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_author_id_created_at_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_reblogs.hive_reblogs_created_at_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_author_id_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_reputation_data.hive_reputation_data_block_num_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_follows.hive_follows_following_state_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_votes.hive_votes_post_id_voter_id_idx
INFO - hive.db.adapter:90 - Closing database connection: 'hive_reblogs'
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_community_id_is_pinned_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts_api_helper.hive_posts_api_helper_author_s_permlink_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_follows.hive_follows_block_num_idx
INFO - hive.db.adapter:90 - Closing database connection: 'hive_reputation_data'
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_votes.hive_votes_block_num_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_feed_cache.hive_feed_cache_block_num_idx
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_reblogs
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_block_num_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_communities.hive_communities_block_num_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_notification_cache.hive_notification_cache_block_num_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_follows.hive_follows_follower_state_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_subscriptions.hive_subscriptions_block_num_idx
INFO - hive.db.adapter:90 - Closing database connection: 'hive_posts_api_helper'
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_reputation_data
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_votes.hive_votes_voter_id_last_update_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_feed_cache.hive_feed_cache_created_at_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_community_id_not_is_pinned_idx
INFO - hive.db.adapter:90 - Closing database connection: 'hive_communities'
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_follows.hive_follows_created_at_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_notification_cache.hive_notification_cache_dst_score_idx
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_posts_api_helper
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_votes.hive_votes_voter_id_post_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_subscriptions.hive_subscriptions_community_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_feed_cache.hive_feed_cache_post_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_block_num_created_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_follows.hive_follows_follower_following_state_idx
INFO - hive.db.adapter:90 - Closing database connection: 'hive_notification_cache'
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_communities
INFO - hive.db.adapter:90 - Closing database connection: 'hive_votes'
INFO - hive.db.adapter:90 - Closing database connection: 'hive_subscriptions'
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_feed_cache.hive_feed_cache_account_id_created_at_post_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_payout_plus_pending_payout_id_idx
INFO - hive.db.adapter:90 - Closing database connection: 'hive_follows'
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_notification_cache
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_votes
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_subscriptions
INFO - hive.db.adapter:90 - Closing database connection: 'hive_feed_cache'
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_cashout_time_id_idx
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_follows
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_feed_cache
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_payout_at_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_updated_at_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_community_id_not_is_paidout_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_category_id_payout_plus_pending_payout_depth_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_payout_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_root_id_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_depth_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_promoted_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_sc_trend_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_parent_id_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_tags_ids_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_sc_hot_id_idx
INFO - hive.db.db_state:209 - Drop index hivemind_app.hive_posts.hive_posts_community_id_id_idx
INFO - hive.db.adapter:90 - Closing database connection: 'hive_posts'
INFO - hive.db.db_state:232 - [MASSIVE] End pre-massive sync hooks for table hive_posts
INFO - hive.db.db_state:422 - [MASSIVE] 10 threads finished creating indexes. Real elapsed time: 0.025
INFO - hive.db.db_state:254 - === DROPPING INDEXES ===
INFO - hive.utils.stats:162 - ####################
INFO - hive.utils.stats:300 - Total DROPPING indexes time
INFO - hive.utils.stats:156 - `hive_posts`: Processed final operations in 0.0243 seconds
INFO - hive.utils.stats:156 - `hive_votes`: Processed final operations in 0.0196 seconds
INFO - hive.utils.stats:156 - `hive_follows`: Processed final operations in 0.0195 seconds
INFO - hive.utils.stats:156 - `hive_feed_cache`: Processed final operations in 0.0184 seconds
INFO - hive.utils.stats:156 - `hive_reputation_data`: Processed final operations in 0.0168 seconds
INFO - hive.utils.stats:156 - `hive_subscriptions`: Processed final operations in 0.0150 seconds
INFO - hive.utils.stats:156 - `hive_communities`: Processed final operations in 0.0145 seconds
INFO - hive.utils.stats:156 - `hive_notification_cache`: Processed final operations in 0.0141 seconds
INFO - hive.utils.stats:156 - `hive_posts_api_helper`: Processed final operations in 0.0138 seconds
INFO - hive.utils.stats:156 - `hive_reblogs`: Processed final operations in 0.0130 seconds
INFO - hive.utils.stats:302 - Current final processing time: 0.1691s.
INFO - hive.db.db_state:256 - Elapsed time: 0.0357s. Calculated elapsed time: 0.1691s. Difference: -0.1334s
INFO - hive.db.db_state:260 - === DROPPING INDEXES ===
INFO - hive.db.db_state:289 - [MASSIVE] Finish pre-massive sync hooks
INFO - hive.indexer.hive_db.haf_functions:25 - Trying to detach app context...
INFO - hive.indexer.hive_db.haf_functions:27 - App context detaching done.
INFO - hive.indexer.sync:137 - [MASSIVE] Attempting to process block range: <492001:80973941>
INFO - hive.indexer.blocks:142 - End-of-sync LIB is set to 80973941, last block that guarantees cashout at end of sync is 80772341
INFO - hive.indexer.hive_db.massive_blocks_data_provider:266 - blocks_data_queue.qsize: 0
INFO - hive.indexer.hive_db.massive_blocks_data_provider:267 - operations_queue.qsize: 0
INFO - hive.indexer.hive_db.massive_blocks_data_provider:268 - blocks_queue.qsize: 0
INFO - hive.indexer.hive_db.massive_blocks_data_provider:274 - Awaiting any blocks to process... 0
ERROR - hive.indexer.sync:237 - Exception caught during fetching blocks data
Traceback (most recent call last):
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/indexer/sync.py", line 235, in _blocks_data_provider
raise exception
File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/indexer/hive_db/massive_blocks_data_provider.py", line 57, in thread_body_get_data
data_rows = self._db.query_all(stmt, is_prepared=True)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/db/adapter.py", line 171, in query_all
return res.fetchall()
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/result.py", line 1072, in fetchall
return self._allrows()
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/result.py", line 401, in _allrows
rows = self._fetchall_impl()
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 1819, in _fetchall_impl
return self.cursor_strategy.fetchall(self, self.cursor)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 995, in fetchall
self.handle_exception(result, dbapi_cursor, e)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 955, in handle_exception
result.connection._handle_dbapi_exception(
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 2138, in _handle_dbapi_exception
util.raise_(exc_info[1], with_traceback=exc_info[2])
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
raise exception
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 991, in fetchall
rows = dbapi_cursor.fetchall()
UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position 61: ordinal not in range(128)
INFO - hive.indexer.sync:256 - === TOTAL STATS ===
INFO - hive.utils.stats:162 - ####################
INFO - hive.utils.stats:342 - Total waiting times
INFO - hive.utils.stats:344 - Total waiting time: 0.0000s.
INFO - hive.utils.stats:162 - ####################
INFO - hive.utils.stats:257 - Total flush times
INFO - hive.utils.stats:259 - Total flushing time: 0.0000s.
INFO - hive.utils.stats:162 - ####################
INFO - hive.utils.stats:205 - All operations present in the processed blocks
INFO - hive.utils.stats:207 - Total time for processing operations time: 0.0000s.
INFO - hive.indexer.sync:261 - Elapsed time: 1.0217s. Calculated elapsed time: 0.0000s. Difference: 1.0217s
INFO - hive.indexer.sync:263 - Highest block processing rate: 0.0000 bps. 0:0
INFO - hive.indexer.sync:266 - Lowest block processing rate: 0.0000 bps. 0:0
INFO - hive.indexer.sync:267 - === TOTAL STATS ===
INFO - hive.indexer.sync:71 - Exiting HAF mode synchronization
WARNING - hive.server.common.payout_stats:16 - Rebuilding payout_stats_view in separate transaction
INFO - hive.indexer.sync:76 - LAST IMPORTED BLOCK IS: 492000
INFO - hive.indexer.sync:77 - LAST COMPLETED BLOCK IS: 1
INFO - hive.indexer.hive_db.haf_functions:37 - Trying to attach app context with block number: 492000
INFO - hive.indexer.hive_db.haf_functions:39 - App context attaching done.
INFO - hive.db.adapter:90 - Closing database connection: 'PostDataCache'
INFO - hive.db.adapter:90 - Closing database connection: 'Reputations'
INFO - hive.db.adapter:90 - Closing database connection: 'Votes'
INFO - hive.db.adapter:90 - Closing database connection: 'Follow'
INFO - hive.db.adapter:90 - Closing database connection: 'Posts'
INFO - hive.db.adapter:90 - Closing database connection: 'Reblog'
INFO - hive.db.adapter:90 - Closing database connection: 'Notify'
INFO - hive.db.adapter:90 - Closing database connection: 'Accounts'
INFO - hive.db.adapter:90 - Closing database connection: 'PayoutStats'
INFO - hive.db.adapter:90 - Closing database connection: 'Mentions'
INFO - hive.db.adapter:90 - Closing database connection: 'root'
INFO - hive.db.adapter:108 - Disposing SQL engine
INFO - hive.conf:261 - The database is disconnected...
Traceback (most recent call last):
File "/home/hivemind/.hivemind-venv/bin/hive", line 8, in <module>
sys.exit(run())
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/cli.py", line 73, in run
launch_mode(mode, conf)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/cli.py", line 87, in launch_mode
sync.run()
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/indexer/sync.py", line 138, in run
self._catchup_irreversible_block(is_massive_sync=True)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/indexer/sync.py", line 194, in _catchup_irreversible_block
self._process_blocks_from_provider(
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/indexer/sync.py", line 350, in _process_blocks_from_provider
raise block_data_provider_exception
File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/indexer/sync.py", line 235, in _blocks_data_provider
raise exception
File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/indexer/hive_db/massive_blocks_data_provider.py", line 57, in thread_body_get_data
data_rows = self._db.query_all(stmt, is_prepared=True)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/hive/db/adapter.py", line 171, in query_all
return res.fetchall()
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/result.py", line 1072, in fetchall
return self._allrows()
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/result.py", line 401, in _allrows
rows = self._fetchall_impl()
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 1819, in _fetchall_impl
return self.cursor_strategy.fetchall(self, self.cursor)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 995, in fetchall
self.handle_exception(result, dbapi_cursor, e)
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 955, in handle_exception
result.connection._handle_dbapi_exception(
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 2138, in _handle_dbapi_exception
util.raise_(exc_info[1], with_traceback=exc_info[2])
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 211, in raise_
raise exception
File "/home/hivemind/.hivemind-venv/lib/python3.8/site-packages/sqlalchemy/engine/cursor.py", line 991, in fetchall
rows = dbapi_cursor.fetchall()
UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position 61: ordinal not in range(128)