Skip to content

Commit 5ff6d0f

Browse files
tnulltnull
committed
Improve logging for de/ser failures and start/stop 
1 parent d2d75a9 commit 5ff6d0f

File tree

2 files changed

+76
-39
lines changed

2 files changed

+76
-39
lines changed

‎src/io/utils.rs‎

Lines changed: 50 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -92,85 +92,104 @@ where
9292
}
9393

9494
/// Read a previously persisted [`NetworkGraph`] from the store.
95-
pub(crate) fn read_network_graph<K: KVStore + Sync + Send, L: Deref>(
95+
pub(crate) fn read_network_graph<K: KVStore + Sync + Send, L: Deref + Clone>(
9696
kv_store: Arc<K>, logger: L,
9797
) -> Result<NetworkGraph<L>, std::io::Error>
9898
where
9999
L::Target: Logger,
100100
{
101101
let mut reader =
102102
kv_store.read(NETWORK_GRAPH_PERSISTENCE_NAMESPACE, NETWORK_GRAPH_PERSISTENCE_KEY)?;
103-
NetworkGraph::read(&mut reader, logger).map_err(|_| {
103+
NetworkGraph::read(&mut reader, logger.clone()).map_err(|e| {
104+
log_error!(logger, "Failed to deserialize NetworkGraph: {}", e);
104105
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize NetworkGraph")
105106
})
106107
}
107108

108109
/// Read a previously persisted [`Scorer`] from the store.
109-
pub(crate) fn read_scorer<K: KVStore + Sync + Send, G: Deref<Target = NetworkGraph<L>>, L: Deref>(
110+
pub(crate) fn read_scorer<
111+
K: KVStore + Send + Sync,
112+
G: Deref<Target = NetworkGraph<L>>,
113+
L: Deref + Clone,
114+
>(
110115
kv_store: Arc<K>, network_graph: G, logger: L,
111116
) -> Result<ProbabilisticScorer<G, L>, std::io::Error>
112117
where
113118
L::Target: Logger,
114119
{
115120
let params = ProbabilisticScoringParameters::default();
116121
let mut reader = kv_store.read(SCORER_PERSISTENCE_NAMESPACE, SCORER_PERSISTENCE_KEY)?;
117-
let args = (params, network_graph, logger);
118-
ProbabilisticScorer::read(&mut reader, args).map_err(|_| {
122+
let args = (params, network_graph, logger.clone());
123+
ProbabilisticScorer::read(&mut reader, args).map_err(|e| {
124+
log_error!(logger, "Failed to deserialize scorer: {}", e);
119125
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize Scorer")
120126
})
121127
}
122128

123129
/// Read previously persisted events from the store.
124-
pub(crate) fn read_event_queue<K: KVStore + Sync + Send, L: Deref>(
130+
pub(crate) fn read_event_queue<K: KVStore + Sync + Send, L: Deref + Clone>(
125131
kv_store: Arc<K>, logger: L,
126132
) -> Result<EventQueue<K, L>, std::io::Error>
127133
where
128134
L::Target: Logger,
129135
{
130136
let mut reader =
131137
kv_store.read(EVENT_QUEUE_PERSISTENCE_NAMESPACE, EVENT_QUEUE_PERSISTENCE_KEY)?;
132-
EventQueue::read(&mut reader, (kv_store, logger)).map_err(|_| {
138+
EventQueue::read(&mut reader, (kv_store, logger.clone())).map_err(|e| {
139+
log_error!(logger, "Failed to deserialize event queue: {}", e);
133140
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize EventQueue")
134141
})
135142
}
136143

137144
/// Read previously persisted peer info from the store.
138-
pub(crate) fn read_peer_info<K: KVStore + Sync + Send, L: Deref>(
145+
pub(crate) fn read_peer_info<K: KVStore + Sync + Send, L: Deref + Clone>(
139146
kv_store: Arc<K>, logger: L,
140147
) -> Result<PeerStore<K, L>, std::io::Error>
141148
where
142149
L::Target: Logger,
143150
{
144151
let mut reader = kv_store.read(PEER_INFO_PERSISTENCE_NAMESPACE, PEER_INFO_PERSISTENCE_KEY)?;
145-
PeerStore::read(&mut reader, (kv_store, logger)).map_err(|_| {
152+
PeerStore::read(&mut reader, (kv_store, logger.clone())).map_err(|e| {
153+
log_error!(logger, "Failed to deserialize peer store: {}", e);
146154
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize PeerStore")
147155
})
148156
}
149157

150158
/// Read previously persisted payments information from the store.
151-
pub(crate) fn read_payments<K: KVStore + Sync + Send>(
152-
kv_store: Arc<K>,
153-
) -> Result<Vec<PaymentDetails>, std::io::Error> {
159+
pub(crate) fn read_payments<K: KVStore + Sync + Send, L: Deref>(
160+
kv_store: Arc<K>, logger: L,
161+
) -> Result<Vec<PaymentDetails>, std::io::Error>
162+
where
163+
L::Target: Logger,
164+
{
154165
let mut res = Vec::new();
155166

156167
for stored_key in kv_store.list(PAYMENT_INFO_PERSISTENCE_NAMESPACE)? {
157168
let payment = PaymentDetails::read(
158169
&mut kv_store.read(PAYMENT_INFO_PERSISTENCE_NAMESPACE, &stored_key)?,
159170
)
160-
.map_err(|_| {
161-
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize Payment")
171+
.map_err(|e| {
172+
log_error!(logger, "Failed to deserialize PaymentDetails: {}", e);
173+
std::io::Error::new(
174+
std::io::ErrorKind::InvalidData,
175+
"Failed to deserialize PaymentDetails",
176+
)
162177
})?;
163178
res.push(payment);
164179
}
165180
Ok(res)
166181
}
167182

168-
pub(crate) fn read_latest_rgs_sync_timestamp<K: KVStore + Sync + Send>(
169-
kv_store: Arc<K>,
170-
) -> Result<u32, std::io::Error> {
183+
pub(crate) fn read_latest_rgs_sync_timestamp<K: KVStore + Sync + Send, L: Deref>(
184+
kv_store: Arc<K>, logger: L,
185+
) -> Result<u32, std::io::Error>
186+
where
187+
L::Target: Logger,
188+
{
171189
let mut reader =
172190
kv_store.read(LATEST_RGS_SYNC_TIMESTAMP_NAMESPACE, LATEST_RGS_SYNC_TIMESTAMP_KEY)?;
173-
u32::read(&mut reader).map_err(|_| {
191+
u32::read(&mut reader).map_err(|e| {
192+
log_error!(logger, "Failed to deserialize latest RGS sync timestamp: {}", e);
174193
std::io::Error::new(
175194
std::io::ErrorKind::InvalidData,
176195
"Failed to deserialize latest RGS sync timestamp",
@@ -199,15 +218,23 @@ where
199218
})
200219
}
201220

202-
pub(crate) fn read_latest_node_ann_bcast_timestamp<K: KVStore + Sync + Send>(
203-
kv_store: Arc<K>,
204-
) -> Result<u64, std::io::Error> {
221+
pub(crate) fn read_latest_node_ann_bcast_timestamp<K: KVStore + Sync + Send, L: Deref>(
222+
kv_store: Arc<K>, logger: L,
223+
) -> Result<u64, std::io::Error>
224+
where
225+
L::Target: Logger,
226+
{
205227
let mut reader = kv_store
206228
.read(LATEST_NODE_ANN_BCAST_TIMESTAMP_NAMESPACE, LATEST_NODE_ANN_BCAST_TIMESTAMP_KEY)?;
207-
u64::read(&mut reader).map_err(|_| {
229+
u64::read(&mut reader).map_err(|e| {
230+
log_error!(
231+
logger,
232+
"Failed to deserialize latest node announcement broadcast timestamp: {}",
233+
e
234+
);
208235
std::io::Error::new(
209236
std::io::ErrorKind::InvalidData,
210-
"Failed to deserialize latest node announcment broadcast timestamp",
237+
"Failed to deserialize latest node announcement broadcast timestamp",
211238
)
212239
})
213240
}

‎src/lib.rs‎

Lines changed: 26 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -469,7 +469,6 @@ impl Builder {
469469
if e.kind() == std::io::ErrorKind::NotFound {
470470
Arc::new(NetworkGraph::new(config.network, Arc::clone(&logger)))
471471
} else {
472-
log_error!(logger, "Failed to read network graph: {}", e.to_string());
473472
panic!("Failed to read network graph: {}", e.to_string());
474473
}
475474
}
@@ -490,7 +489,6 @@ impl Builder {
490489
Arc::clone(&logger),
491490
)))
492491
} else {
493-
log_error!(logger, "Failed to read scorer: {}", e.to_string());
494492
panic!("Failed to read scorer: {}", e.to_string());
495493
}
496494
}
@@ -609,8 +607,11 @@ impl Builder {
609607
p2p_source
610608
}
611609
GossipSourceConfig::RapidGossipSync(rgs_server) => {
612-
let latest_sync_timestamp =
613-
io::utils::read_latest_rgs_sync_timestamp(Arc::clone(&kv_store)).unwrap_or(0);
610+
let latest_sync_timestamp = io::utils::read_latest_rgs_sync_timestamp(
611+
Arc::clone(&kv_store),
612+
Arc::clone(&logger),
613+
)
614+
.unwrap_or(0);
614615
Arc::new(GossipSource::new_rgs(
615616
rgs_server.clone(),
616617
latest_sync_timestamp,
@@ -648,15 +649,17 @@ impl Builder {
648649
));
649650

650651
// Init payment info storage
651-
let payment_store = match io::utils::read_payments(Arc::clone(&kv_store)) {
652-
Ok(payments) => {
653-
Arc::new(PaymentStore::new(payments, Arc::clone(&kv_store), Arc::clone(&logger)))
654-
}
655-
Err(e) => {
656-
log_error!(logger, "Failed to read payment information: {}", e.to_string());
657-
panic!("Failed to read payment information: {}", e.to_string());
658-
}
659-
};
652+
let payment_store =
653+
match io::utils::read_payments(Arc::clone(&kv_store), Arc::clone(&logger)) {
654+
Ok(payments) => Arc::new(PaymentStore::new(
655+
payments,
656+
Arc::clone(&kv_store),
657+
Arc::clone(&logger),
658+
)),
659+
Err(e) => {
660+
panic!("Failed to read payment information: {}", e.to_string());
661+
}
662+
};
660663

661664
let event_queue =
662665
match io::utils::read_event_queue(Arc::clone(&kv_store), Arc::clone(&logger)) {
@@ -665,7 +668,6 @@ impl Builder {
665668
if e.kind() == std::io::ErrorKind::NotFound {
666669
Arc::new(EventQueue::new(Arc::clone(&kv_store), Arc::clone(&logger)))
667670
} else {
668-
log_error!(logger, "Failed to read event queue: {}", e.to_string());
669671
panic!("Failed to read event queue: {}", e.to_string());
670672
}
671673
}
@@ -678,7 +680,6 @@ impl Builder {
678680
if e.kind() == std::io::ErrorKind::NotFound {
679681
Arc::new(PeerStore::new(Arc::clone(&kv_store), Arc::clone(&logger)))
680682
} else {
681-
log_error!(logger, "Failed to read peer store: {}", e.to_string());
682683
panic!("Failed to read peer store: {}", e.to_string());
683684
}
684685
}
@@ -747,6 +748,8 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
747748
return Err(Error::AlreadyRunning);
748749
}
749750

751+
log_info!(self.logger, "Starting up LDK Node on network: {}", self.config.network);
752+
750753
let runtime = tokio::runtime::Builder::new_multi_thread().enable_all().build().unwrap();
751754

752755
let event_handler = Arc::new(EventHandler::new(
@@ -969,7 +972,7 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
969972
return;
970973
}
971974
_ = interval.tick() => {
972-
let skip_broadcast = match io::utils::read_latest_node_ann_bcast_timestamp(Arc::clone(&bcast_store)) {
975+
let skip_broadcast = match io::utils::read_latest_node_ann_bcast_timestamp(Arc::clone(&bcast_store), Arc::clone(&bcast_logger)) {
973976
Ok(latest_bcast_time_secs) => {
974977
// Skip if the time hasn't elapsed yet.
975978
let next_bcast_unix_time = SystemTime::UNIX_EPOCH + Duration::from_secs(latest_bcast_time_secs) + NODE_ANN_BCAST_INTERVAL;
@@ -1049,6 +1052,8 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
10491052
});
10501053

10511054
*runtime_lock = Some(runtime);
1055+
1056+
log_info!(self.logger, "Startup complete.");
10521057
Ok(())
10531058
}
10541059

@@ -1057,6 +1062,9 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
10571062
/// After this returns most API methods will return [`Error::NotRunning`].
10581063
pub fn stop(&self) -> Result<(), Error> {
10591064
let runtime = self.runtime.write().unwrap().take().ok_or(Error::NotRunning)?;
1065+
1066+
log_info!(self.logger, "Shutting down LDK Node...");
1067+
10601068
// Stop the runtime.
10611069
match self.stop_sender.send(()) {
10621070
Ok(_) => (),
@@ -1074,6 +1082,8 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
10741082
self.peer_manager.disconnect_all_peers();
10751083

10761084
runtime.shutdown_timeout(Duration::from_secs(10));
1085+
1086+
log_info!(self.logger, "Shutdown complete.");
10771087
Ok(())
10781088
}
10791089

0 commit comments

Comments
 (0)