diff --git a/block-filter/src/filter.rs b/block-filter/src/filter.rs index 04e8a6566b..56fcc92f6b 100644 --- a/block-filter/src/filter.rs +++ b/block-filter/src/filter.rs @@ -1,5 +1,5 @@ use ckb_async_runtime::tokio::{self, task::block_in_place}; -use ckb_logger::{debug, warn}; +use ckb_logger::{debug, info, warn}; use ckb_shared::Shared; use ckb_stop_handler::{new_tokio_exit_rx, CancellationToken}; use ckb_store::{ChainDB, ChainStore}; @@ -63,7 +63,7 @@ impl BlockFilter { new_block_watcher.borrow_and_update(); } _ = stop_rx.cancelled() => { - debug!("BlockFilter received exit signal, exit now"); + info!("BlockFilter received exit signal, exit now"); break }, else => break, diff --git a/chain/src/chain.rs b/chain/src/chain.rs index c95ad4853c..2f0789b4a4 100644 --- a/chain/src/chain.rs +++ b/chain/src/chain.rs @@ -257,7 +257,7 @@ impl ChainService { }, }, recv(signal_receiver) -> _ => { - debug!("ChainService received exit signal, exit now"); + info!("ChainService received exit signal, exit now"); break; } } diff --git a/ckb-bin/src/helper.rs b/ckb-bin/src/helper.rs index 7dee9de15d..21c93732b8 100644 --- a/ckb-bin/src/helper.rs +++ b/ckb-bin/src/helper.rs @@ -8,7 +8,7 @@ pub fn deadlock_detection() {} #[cfg(feature = "deadlock_detection")] pub fn deadlock_detection() { use ckb_channel::select; - use ckb_logger::{debug, warn}; + use ckb_logger::warn; use ckb_stop_handler::{new_crossbeam_exit_rx, register_thread}; use ckb_util::parking_lot::deadlock; use std::{thread, time::Duration}; @@ -36,7 +36,7 @@ pub fn deadlock_detection() { }, recv(stop_rx) -> _ =>{ - debug!("deadlock_detection received exit signal, stopped"); + info!("deadlock_detection received exit signal, stopped"); return; } } diff --git a/ckb-bin/src/lib.rs b/ckb-bin/src/lib.rs index 8596f504d0..81d9376b07 100644 --- a/ckb-bin/src/lib.rs +++ b/ckb-bin/src/lib.rs @@ -8,7 +8,7 @@ mod subcommand; use ckb_app_config::{cli, ExitCode, Setup}; use ckb_async_runtime::new_global_runtime; use ckb_build_info::Version; -use ckb_logger::{debug, info}; +use ckb_logger::info; use ckb_network::tokio; use helper::raise_fd_limit; use setup_guard::SetupGuard; @@ -80,9 +80,9 @@ pub fn run_app(version: Version) -> Result<(), ExitCode> { handle.drop_guard(); tokio::task::block_in_place(|| { - debug!("waiting all tokio tasks done"); + info!("waiting all tokio tasks exit..."); handle_stop_rx.blocking_recv(); - info!("ckb shutdown"); + info!("all tokio tasks and threads have exited, ckb shutdown"); }); } diff --git a/miner/src/client.rs b/miner/src/client.rs index c598f5af9a..dda47570a7 100644 --- a/miner/src/client.rs +++ b/miner/src/client.rs @@ -4,7 +4,7 @@ use ckb_app_config::MinerClientConfig; use ckb_async_runtime::Handle; use ckb_channel::Sender; use ckb_jsonrpc_types::{Block as JsonBlock, BlockTemplate}; -use ckb_logger::{debug, error}; +use ckb_logger::{debug, error, info}; use ckb_stop_handler::{new_tokio_exit_rx, CancellationToken}; use ckb_types::{ packed::{Block, Byte32}, @@ -87,7 +87,7 @@ impl Rpc { }); }, _ = stop_rx.cancelled() => { - debug!("Rpc server received exit signal, exit now"); + info!("Rpc server received exit signal, exit now"); break }, else => break @@ -235,7 +235,7 @@ Otherwise ckb-miner does not work properly and will behave as it stopped committ let stop_rx: CancellationToken = new_tokio_exit_rx(); let graceful = server.with_graceful_shutdown(async move { stop_rx.cancelled().await; - debug!("Miner client received exit signal, exit now"); + info!("Miner client received exit signal, exit now"); }); if let Err(e) = graceful.await { @@ -255,7 +255,7 @@ Otherwise ckb-miner does not work properly and will behave as it stopped committ self.fetch_block_template().await; } _ = stop_rx.cancelled() => { - debug!("Miner client pool_block_template received exit signal, exit now"); + info!("Miner client pool_block_template received exit signal, exit now"); break }, else => break, diff --git a/miner/src/miner.rs b/miner/src/miner.rs index 101f156b4d..436ea53ca4 100644 --- a/miner/src/miner.rs +++ b/miner/src/miner.rs @@ -105,7 +105,7 @@ impl Miner { }, }, recv(stop_rx) -> _msg => { - debug!("miner received exit signal, stopped"); + info!("miner received exit signal, stopped"); break; } }; diff --git a/network/src/network.rs b/network/src/network.rs index d7ce369897..78567b02ee 100644 --- a/network/src/network.rs +++ b/network/src/network.rs @@ -1127,11 +1127,12 @@ impl NetworkService { loop { tokio::select! { _ = receiver.cancelled() => { - debug!("NetworkService receive exit signal, start shutdown..."); + info!("NetworkService receive exit signal, start shutdown..."); let _ = p2p_control.shutdown().await; // Drop senders to stop all corresponding background task drop(bg_signals); + info!("NetworkService shutdown now"); break; }, else => { diff --git a/notify/src/lib.rs b/notify/src/lib.rs index 41d1451e04..b6a0172a8a 100644 --- a/notify/src/lib.rs +++ b/notify/src/lib.rs @@ -1,7 +1,7 @@ //! TODO(doc): @quake use ckb_app_config::NotifyConfig; use ckb_async_runtime::Handle; -use ckb_logger::{debug, error, trace}; +use ckb_logger::{debug, error, info, trace}; use ckb_stop_handler::{new_tokio_exit_rx, CancellationToken}; use ckb_types::packed::Byte32; use ckb_types::{ @@ -178,7 +178,7 @@ impl NotifyService { Some(msg) = network_alert_register_receiver.recv() => { self.handle_register_network_alert(msg) }, Some(msg) = network_alert_receiver.recv() => { self.handle_notify_network_alert(msg) }, _ = signal_receiver.cancelled() => { - debug!("NotifyService received exit signal, exit now"); + info!("NotifyService received exit signal, exit now"); break; } else => break, diff --git a/sync/src/synchronizer/mod.rs b/sync/src/synchronizer/mod.rs index 1d66df420b..817acfb549 100644 --- a/sync/src/synchronizer/mod.rs +++ b/sync/src/synchronizer/mod.rs @@ -146,7 +146,7 @@ impl BlockFetchCMD { } } recv(stop_signal) -> _ => { - debug!("thread BlockDownload received exit signal, exit now"); + info!("BlockDownload received exit signal, exit now"); return; } } diff --git a/sync/src/types/header_map/mod.rs b/sync/src/types/header_map/mod.rs index 975c7b9075..78939164b6 100644 --- a/sync/src/types/header_map/mod.rs +++ b/sync/src/types/header_map/mod.rs @@ -1,5 +1,5 @@ use ckb_async_runtime::Handle; -use ckb_logger::debug; +use ckb_logger::info; use ckb_stop_handler::{new_tokio_exit_rx, CancellationToken}; use ckb_types::packed::Byte32; use std::sync::Arc; @@ -56,7 +56,7 @@ impl HeaderMap { map.limit_memory(); } _ = stop_rx.cancelled() => { - debug!("HeaderMap limit_memory received exit signal, exit now"); + info!("HeaderMap limit_memory received exit signal, exit now"); break }, } diff --git a/tx-pool/src/chunk_process.rs b/tx-pool/src/chunk_process.rs index 1cae5abbe8..cf0a82b80a 100644 --- a/tx-pool/src/chunk_process.rs +++ b/tx-pool/src/chunk_process.rs @@ -4,7 +4,7 @@ use crate::try_or_return_with_snapshot; use crate::{error::Reject, service::TxPoolService}; use ckb_chain_spec::consensus::Consensus; use ckb_error::Error; -use ckb_logger::debug; +use ckb_logger::info; use ckb_snapshot::Snapshot; use ckb_store::data_loader_wrapper::AsDataLoader; use ckb_traits::{CellDataProvider, ExtensionProvider, HeaderProvider}; @@ -85,7 +85,7 @@ impl ChunkProcess { } }, _ = self.signal.cancelled() => { - debug!("TxPool received exit signal, exit now"); + info!("TxPool chunk_command service received exit signal, exit now"); break }, else => break, diff --git a/tx-pool/src/service.rs b/tx-pool/src/service.rs index 696fbeeee8..033615a2a7 100644 --- a/tx-pool/src/service.rs +++ b/tx-pool/src/service.rs @@ -14,8 +14,8 @@ use ckb_chain_spec::consensus::Consensus; use ckb_channel::oneshot; use ckb_error::AnyError; use ckb_jsonrpc_types::BlockTemplate; +use ckb_logger::error; use ckb_logger::info; -use ckb_logger::{debug, error}; use ckb_network::{NetworkController, PeerIndex}; use ckb_snapshot::Snapshot; use ckb_stop_handler::new_tokio_exit_rx; @@ -517,6 +517,7 @@ impl TxPoolServiceBuilder { _ = signal_receiver.cancelled() => { info!("TxPool is saving, please wait..."); process_service.save_pool().await; + info!("TxPool process_service exit now"); break }, else => break, @@ -543,7 +544,7 @@ impl TxPoolServiceBuilder { block_assembler::process(service_clone, &message).await; }, _ = signal_receiver.cancelled() => { - debug!("TxPool received exit signal, exit now"); + info!("TxPool block_assembler process service received exit signal, exit now"); break }, else => break, @@ -578,7 +579,7 @@ impl TxPoolServiceBuilder { queue.clear(); } _ = signal_receiver.cancelled() => { - debug!("TxPool received exit signal, exit now"); + info!("TxPool block_assembler process service received exit signal, exit now"); break }, else => break, @@ -616,7 +617,7 @@ impl TxPoolServiceBuilder { service.update_block_assembler_after_tx_pool_reorg().await; }, _ = signal_receiver.cancelled() => { - debug!("TxPool received exit signal, exit now"); + info!("TxPool reorg process service received exit signal, exit now"); break }, else => break, diff --git a/util/app-config/src/tests/ckb_run_replay.bats b/util/app-config/src/tests/ckb_run_replay.bats index c6943eeb5b..6603a1aea8 100644 --- a/util/app-config/src/tests/ckb_run_replay.bats +++ b/util/app-config/src/tests/ckb_run_replay.bats @@ -24,7 +24,7 @@ function ckb_run { #@test run _ckb_run [ "$status" -eq 0 ] # assert_output --regexp "ckb_chain::chain.*block number:.*, hash:.*, size:.*, cycles:.*" - assert_output --regexp "ckb_bin ckb shutdown" + assert_output --regexp "INFO ckb_bin all tokio tasks and threads have exited, ckb shutdown" } function ckb_replay { #@test diff --git a/util/app-config/src/tests/graceful_shutdown.bats b/util/app-config/src/tests/graceful_shutdown.bats index eb906c3949..b05c006255 100644 --- a/util/app-config/src/tests/graceful_shutdown.bats +++ b/util/app-config/src/tests/graceful_shutdown.bats @@ -3,13 +3,12 @@ bats_load_library 'bats-assert' bats_load_library 'bats-support' _ckb_graceful_shutdown() { - ckb run -C ${CKB_DIRNAME} &> ${TMP_DIR}/ckb_run.log & + ckb run --indexer -C ${CKB_DIRNAME} &> ${TMP_DIR}/ckb_run.log & PID=$! sleep 10 kill ${PID} while kill -0 ${PID}; do - echo "waiting for ckb to exit" sleep 1 done @@ -20,24 +19,25 @@ function ckb_graceful_shutdown { #@test run _ckb_graceful_shutdown [ "$status" -eq 0 ] + assert_output --regexp "INFO ckb_bin::subcommand::run Trapped exit signal, exiting..." - assert_output --regexp "DEBUG ckb_stop_handler::stop_register received exit signal, broadcasting exit signal to all threads" - assert_output --regexp "DEBUG ckb_tx_pool::chunk_process TxPool received exit signal, exit now" - assert_output --regexp "DEBUG ckb_sync::types::header_map HeaderMap limit_memory received exit signal, exit now" - assert_output --regexp "DEBUG ckb_chain::chain ChainService received exit signal, exit now" - assert_output --regexp "DEBUG ckb_sync::synchronizer thread BlockDownload received exit signal, exit now" - assert_output --regexp "DEBUG ckb_network::network NetworkService receive exit signal, start shutdown..." + assert_output --regexp "INFO ckb_chain::chain ChainService received exit signal, exit now" + assert_output --regexp "INFO ckb_sync::synchronizer BlockDownload received exit signal, exit now" + assert_output --regexp "INFO ckb_tx_pool::chunk_process TxPool chunk_command service received exit signal, exit now" assert_output --regexp "INFO ckb_tx_pool::service TxPool is saving, please wait..." - assert_output --regexp "DEBUG ckb_tx_pool::service TxPool received exit signal, exit now" - assert_output --regexp "DEBUG ckb_block_filter::filter BlockFilter received exit signal, exit now" - assert_output --regexp "DEBUG ckb_network::services::dump_peer_store dump peer store before exit" - assert_output --regexp "DEBUG ckb_notify NotifyService received exit signal, exit now" - assert_output --regexp "DEBUG ckb_stop_handler::stop_register wait thread ChainService done" - assert_output --regexp "DEBUG ckb_stop_handler::stop_register wait thread BlockDownload done" - assert_output --regexp "DEBUG ckb_stop_handler::stop_register all ckb threads have been stopped" - assert_output --regexp "DEBUG ckb_bin waiting all tokio tasks done" + assert_output --regexp "INFO ckb_tx_pool::service TxPool reorg process service received exit signal, exit now" + assert_output --regexp "INFO ckb_indexer::service Indexer received exit signal, exit now" + assert_output --regexp "INFO ckb_notify NotifyService received exit signal, exit now" + assert_output --regexp "INFO ckb_block_filter::filter BlockFilter received exit signal, exit now" + assert_output --regexp "INFO ckb_sync::types::header_map HeaderMap limit_memory received exit signal, exit now" + assert_output --regexp "INFO ckb_network::network NetworkService receive exit signal, start shutdown..." + assert_output --regexp "INFO ckb_network::network NetworkService shutdown now" assert_output --regexp "INFO ckb_tx_pool::process TxPool save successfully" - assert_output --regexp "INFO ckb_bin ckb shutdown" + assert_output --regexp "INFO ckb_tx_pool::service TxPool process_service exit now" + assert_output --regexp "INFO ckb_stop_handler::stop_register wait thread ChainService done" + assert_output --regexp "INFO ckb_stop_handler::stop_register wait thread BlockDownload done" + assert_output --regexp "INFO ckb_bin waiting all tokio tasks exit..." + assert_output --regexp "INFO ckb_bin all tokio tasks and threads have exited, ckb shutdown" } teardown_file() { diff --git a/util/indexer/src/service.rs b/util/indexer/src/service.rs index 1526074dd5..56f0680599 100644 --- a/util/indexer/src/service.rs +++ b/util/indexer/src/service.rs @@ -16,7 +16,7 @@ use ckb_jsonrpc_types::{ IndexerScriptSearchMode, IndexerScriptType, IndexerSearchKey, IndexerTip, IndexerTx, IndexerTxWithCell, IndexerTxWithCells, JsonBytes, Uint32, }; -use ckb_logger::{debug, error, info}; +use ckb_logger::{error, info}; use ckb_notify::NotifyController; use ckb_stop_handler::{new_tokio_exit_rx, CancellationToken}; use ckb_store::ChainStore; @@ -118,7 +118,7 @@ impl IndexerService { } } _ = stop.cancelled() => { - debug!("Indexer received exit signal, exit now"); + info!("Indexer received exit signal, exit now"); break }, else => break, @@ -204,7 +204,7 @@ impl IndexerService { } } _ = stop.cancelled() => { - debug!("Indexer received exit signal, exit now"); + info!("Indexer received exit signal, exit now"); break }, } diff --git a/util/metrics-service/src/lib.rs b/util/metrics-service/src/lib.rs index 4206a3d0aa..1b88171de0 100644 --- a/util/metrics-service/src/lib.rs +++ b/util/metrics-service/src/lib.rs @@ -10,7 +10,7 @@ use hyper::{ use prometheus::Encoder as _; use ckb_async_runtime::Handle; -use ckb_logger::debug; +use ckb_logger::info; use ckb_metrics_config::{Config, Exporter, Target}; use ckb_stop_handler::{new_tokio_exit_rx, CancellationToken}; use ckb_util::strings; @@ -66,7 +66,7 @@ fn run_exporter(exporter: Exporter, handle: &Handle) -> Result<(), String> { .with_graceful_shutdown(async { let exit_rx: CancellationToken = new_tokio_exit_rx(); exit_rx.cancelled().await; - debug!("prometheus server received exit signal, exit now"); + info!("prometheus server received exit signal, exit now"); }); if let Err(err) = server.await { ckb_logger::error!("prometheus server error: {}", err); diff --git a/util/stop-handler/src/stop_register.rs b/util/stop-handler/src/stop_register.rs index d7f2a7f560..403ab24d83 100644 --- a/util/stop-handler/src/stop_register.rs +++ b/util/stop-handler/src/stop_register.rs @@ -1,5 +1,5 @@ use ckb_channel::TrySendError; -use ckb_logger::{debug, error, info, trace, warn}; +use ckb_logger::{debug, info, trace, warn}; use ckb_util::Mutex; use tokio_util::sync::CancellationToken; @@ -17,7 +17,7 @@ pub fn wait_all_ckb_services_exit() { for (name, join_handle) in handles.thread_handles.drain(..) { match join_handle.join() { Ok(_) => { - debug!("wait thread {} done", name); + info!("wait thread {} done", name); } Err(e) => { warn!("wait thread {}: ERROR: {:?}", name, e) @@ -61,9 +61,9 @@ pub fn broadcast_exit_signals() { .iter() .for_each(|tx| match tx.try_send(()) { Ok(_) => {} - Err(TrySendError::Full(_)) => error!("send exit signal to channel failed since the channel is full, this should not happen"), + Err(TrySendError::Full(_)) => info!("ckb process has received exit signal"), Err(TrySendError::Disconnected(_)) => { - info!("broadcast thread: channel is disconnected") + debug!("broadcast thread: channel is disconnected") } }); }