Skip to content

Commit e8f8db3

Browse files
tnulltnull
committed
Improve logging for de/ser failures and start/stop 
1 parent 319f4ae commit e8f8db3

File tree

2 files changed

+73
-39
lines changed

2 files changed

+73
-39
lines changed

‎src/io/utils.rs

Lines changed: 47 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -92,85 +92,101 @@ 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(|_| {
104-
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize NetworkGraph")
103+
NetworkGraph::read(&mut reader, logger.clone()).map_err(|e| {
104+
log_error!(logger, "Failed to deserialize network graph: {}", e);
105+
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize network graph")
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(|_| {
171+
.map_err(|e| {
172+
log_error!(logger, "Failed to deserialize Payment: {}", e);
161173
std::io::Error::new(std::io::ErrorKind::InvalidData, "Failed to deserialize Payment")
162174
})?;
163175
res.push(payment);
164176
}
165177
Ok(res)
166178
}
167179

168-
pub(crate) fn read_latest_rgs_sync_timestamp<K: KVStore + Sync + Send>(
169-
kv_store: Arc<K>,
170-
) -> Result<u32, std::io::Error> {
180+
pub(crate) fn read_latest_rgs_sync_timestamp<K: KVStore + Sync + Send, L: Deref>(
181+
kv_store: Arc<K>, logger: L,
182+
) -> Result<u32, std::io::Error>
183+
where
184+
L::Target: Logger,
185+
{
171186
let mut reader =
172187
kv_store.read(LATEST_RGS_SYNC_TIMESTAMP_NAMESPACE, LATEST_RGS_SYNC_TIMESTAMP_KEY)?;
173-
u32::read(&mut reader).map_err(|_| {
188+
u32::read(&mut reader).map_err(|e| {
189+
log_error!(logger, "Failed to deserialize latest RGS sync timestamp: {}", e);
174190
std::io::Error::new(
175191
std::io::ErrorKind::InvalidData,
176192
"Failed to deserialize latest RGS sync timestamp",
@@ -199,15 +215,23 @@ where
199215
})
200216
}
201217

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> {
218+
pub(crate) fn read_latest_node_ann_bcast_timestamp<K: KVStore + Sync + Send, L: Deref>(
219+
kv_store: Arc<K>, logger: L,
220+
) -> Result<u64, std::io::Error>
221+
where
222+
L::Target: Logger,
223+
{
205224
let mut reader = kv_store
206225
.read(LATEST_NODE_ANN_BCAST_TIMESTAMP_NAMESPACE, LATEST_NODE_ANN_BCAST_TIMESTAMP_KEY)?;
207-
u64::read(&mut reader).map_err(|_| {
226+
u64::read(&mut reader).map_err(|e| {
227+
log_error!(
228+
logger,
229+
"Failed to deserialize latest node announcement broadcast timestamp: {}",
230+
e
231+
);
208232
std::io::Error::new(
209233
std::io::ErrorKind::InvalidData,
210-
"Failed to deserialize latest node announcment broadcast timestamp",
234+
"Failed to deserialize latest node announcement broadcast timestamp",
211235
)
212236
})
213237
}

‎src/lib.rs

Lines changed: 26 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -431,7 +431,6 @@ impl Builder {
431431
if e.kind() == std::io::ErrorKind::NotFound {
432432
Arc::new(NetworkGraph::new(config.network, Arc::clone(&logger)))
433433
} else {
434-
log_error!(logger, "Failed to read network graph: {}", e.to_string());
435434
panic!("Failed to read network graph: {}", e.to_string());
436435
}
437436
}
@@ -452,7 +451,6 @@ impl Builder {
452451
Arc::clone(&logger),
453452
)))
454453
} else {
455-
log_error!(logger, "Failed to read scorer: {}", e.to_string());
456454
panic!("Failed to read scorer: {}", e.to_string());
457455
}
458456
}
@@ -570,8 +568,11 @@ impl Builder {
570568
p2p_source
571569
}
572570
GossipSourceConfig::RapidGossipSync(rgs_server) => {
573-
let latest_sync_timestamp =
574-
io::utils::read_latest_rgs_sync_timestamp(Arc::clone(&kv_store)).unwrap_or(0);
571+
let latest_sync_timestamp = io::utils::read_latest_rgs_sync_timestamp(
572+
Arc::clone(&kv_store),
573+
Arc::clone(&logger),
574+
)
575+
.unwrap_or(0);
575576
Arc::new(GossipSource::new_rgs(
576577
rgs_server.clone(),
577578
latest_sync_timestamp,
@@ -609,15 +610,17 @@ impl Builder {
609610
));
610611

611612
// Init payment info storage
612-
let payment_store = match io::utils::read_payments(Arc::clone(&kv_store)) {
613-
Ok(payments) => {
614-
Arc::new(PaymentStore::new(payments, Arc::clone(&kv_store), Arc::clone(&logger)))
615-
}
616-
Err(e) => {
617-
log_error!(logger, "Failed to read payment information: {}", e.to_string());
618-
panic!("Failed to read payment information: {}", e.to_string());
619-
}
620-
};
613+
let payment_store =
614+
match io::utils::read_payments(Arc::clone(&kv_store), Arc::clone(&logger)) {
615+
Ok(payments) => Arc::new(PaymentStore::new(
616+
payments,
617+
Arc::clone(&kv_store),
618+
Arc::clone(&logger),
619+
)),
620+
Err(e) => {
621+
panic!("Failed to read payment information: {}", e.to_string());
622+
}
623+
};
621624

622625
let event_queue =
623626
match io::utils::read_event_queue(Arc::clone(&kv_store), Arc::clone(&logger)) {
@@ -626,7 +629,6 @@ impl Builder {
626629
if e.kind() == std::io::ErrorKind::NotFound {
627630
Arc::new(EventQueue::new(Arc::clone(&kv_store), Arc::clone(&logger)))
628631
} else {
629-
log_error!(logger, "Failed to read event queue: {}", e.to_string());
630632
panic!("Failed to read event queue: {}", e.to_string());
631633
}
632634
}
@@ -639,7 +641,6 @@ impl Builder {
639641
if e.kind() == std::io::ErrorKind::NotFound {
640642
Arc::new(PeerStore::new(Arc::clone(&kv_store), Arc::clone(&logger)))
641643
} else {
642-
log_error!(logger, "Failed to read peer store: {}", e.to_string());
643644
panic!("Failed to read peer store: {}", e.to_string());
644645
}
645646
}
@@ -712,6 +713,8 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
712713
return Err(Error::AlreadyRunning);
713714
}
714715

716+
log_info!(self.logger, "Starting up LDK Node on network: {}", self.config.network);
717+
715718
let runtime = tokio::runtime::Builder::new_multi_thread().enable_all().build().unwrap();
716719

717720
let event_handler = Arc::new(EventHandler::new(
@@ -934,7 +937,7 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
934937
return;
935938
}
936939
_ = interval.tick() => {
937-
let skip_broadcast = match io::utils::read_latest_node_ann_bcast_timestamp(Arc::clone(&bcast_store)) {
940+
let skip_broadcast = match io::utils::read_latest_node_ann_bcast_timestamp(Arc::clone(&bcast_store), Arc::clone(&bcast_logger)) {
938941
Ok(latest_bcast_time_secs) => {
939942
// Skip if the time hasn't elapsed yet.
940943
let next_bcast_unix_time = SystemTime::UNIX_EPOCH + Duration::from_secs(latest_bcast_time_secs) + NODE_ANN_BCAST_INTERVAL;
@@ -1014,6 +1017,8 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
10141017
});
10151018

10161019
*runtime_lock = Some(runtime);
1020+
1021+
log_info!(self.logger, "Startup complete.");
10171022
Ok(())
10181023
}
10191024

@@ -1022,6 +1027,9 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
10221027
/// After this returns most API methods will return [`Error::NotRunning`].
10231028
pub fn stop(&self) -> Result<(), Error> {
10241029
let runtime = self.runtime.write().unwrap().take().ok_or(Error::NotRunning)?;
1030+
1031+
log_info!(self.logger, "Shutting down LDK Node...");
1032+
10251033
// Stop the runtime.
10261034
match self.stop_sender.send(()) {
10271035
Ok(_) => (),
@@ -1039,6 +1047,8 @@ impl<K: KVStore + Sync + Send + 'static> Node<K> {
10391047
self.peer_manager.disconnect_all_peers();
10401048

10411049
runtime.shutdown_timeout(Duration::from_secs(10));
1050+
1051+
log_info!(self.logger, "Shutdown complete.");
10421052
Ok(())
10431053
}
10441054

0 commit comments

Comments
 (0)