From 47ec706393829e658c7e51d26502cf82f140da47 Mon Sep 17 00:00:00 2001 From: Christian Decker Date: Mon, 5 Jan 2026 15:38:26 +0100 Subject: [PATCH 1/2] signer: Made signer phases more visible, and prevented 2 crashes --- libs/gl-client/src/signer/mod.rs | 54 ++++++++++++++++++++++++-------- 1 file changed, 41 insertions(+), 13 deletions(-) diff --git a/libs/gl-client/src/signer/mod.rs b/libs/gl-client/src/signer/mod.rs index 8533db573..90fde12b7 100644 --- a/libs/gl-client/src/signer/mod.rs +++ b/libs/gl-client/src/signer/mod.rs @@ -409,7 +409,7 @@ impl Signer { .await? .into_inner(); - debug!("Starting to stream signer requests"); + info!("Starting to stream signer requests"); loop { let req = match stream .message() @@ -560,8 +560,17 @@ impl Signer { let root_handler = self.handler_with_approver(approver)?; log::trace!("Updating state from context"); - update_state_from_context(&ctxrequests, &root_handler) - .expect("Updating state from context requests"); + if let Err(e) = update_state_from_context(&ctxrequests, &root_handler) { + error!("Failed to update state from context: {:?}", e); + report::Reporter::report(crate::pb::scheduler::SignerRejection { + msg: format!("Failed to update state from context: {:?}", e), + request: Some(req.clone()), + git_version: GITHASH.to_string(), + node_id: self.node_id(), + }) + .await; + return Err(Error::Other(anyhow!("Failed to update state from context: {:?}", e))); + } log::trace!("State updated"); // Match over root and client handler. @@ -746,6 +755,8 @@ impl Signer { // Upgrade node if necessary. // If it fails due to connection error, sleep and retry. Re-throw all other errors. loop { + let call_start = tokio::time::Instant::now(); + debug!("Sending maybe_upgrade to {}", self.version()); #[allow(deprecated)] let res = scheduler .maybe_upgrade(UpgradeRequest { @@ -758,6 +769,11 @@ impl Signer { .collect(), }) .await; + debug!( + "Server returned {:?} after {}s", + res, + call_start.elapsed().as_secs() + ); match res { Err(e) => match e.code() { @@ -785,7 +801,7 @@ impl Signer { mut scheduler: SchedulerClient, ) -> Result<(), anyhow::Error> { loop { - debug!("Calling scheduler.get_node_info"); + info!("Calling scheduler.get_node_info"); let node_info_res = scheduler .get_node_info(NodeInfoRequest { node_id: self.id.clone(), @@ -801,7 +817,7 @@ impl Signer { let node_info = match node_info_res.map(|v| v.into_inner()) { Ok(v) => { - debug!("Got node_info from scheduler: {:?}", v); + info!("Got node_info from scheduler: {:?}", v); v } Err(e) => { @@ -1141,7 +1157,11 @@ fn update_state_from_context( requests .iter() - .for_each(|r| update_state_from_request(r, &node).unwrap()); + .for_each(|r| { + if let Err(e) = update_state_from_request(r, &node) { + log::warn!("Failed to update state from request: {:?}", e); + } + }); Ok(()) } @@ -1155,13 +1175,21 @@ fn update_state_from_request( model::Request::SendPay(model::cln::SendpayRequest { bolt11: Some(inv), .. }) => { - let invoice = Invoice::from_str(inv).unwrap(); - log::debug!( - "Adding invoice {:?} as side-effect of this sendpay {:?}", - invoice, - request - ); - node.add_invoice(invoice).unwrap(); + match Invoice::from_str(inv) { + Ok(invoice) => { + log::debug!( + "Adding invoice {:?} as side-effect of this sendpay {:?}", + invoice, + request + ); + if let Err(e) = node.add_invoice(invoice) { + log::warn!("Failed to add invoice to node state: {:?}", e); + } + } + Err(e) => { + log::warn!("Failed to parse invoice from sendpay request: {:?}", e); + } + } } _ => {} } From fea41c4797cc2e213ce1e8d012aeab0fe7da3dc2 Mon Sep 17 00:00:00 2001 From: Christian Decker Date: Mon, 5 Jan 2026 17:35:54 +0100 Subject: [PATCH 2/2] signer: Bolt down error reporting for signer The signer rejections now also trigger on things that are not strictly validation errors. Now we report state loading, updating and diffing errors, as well as parsing errors of arguments, and calls. --- .gitignore | 1 + libs/gl-client/src/lib.rs | 3 + libs/gl-client/src/signer/auth.rs | 20 ++++-- libs/gl-client/src/signer/mod.rs | 114 ++++++++++++++++++++---------- 4 files changed, 96 insertions(+), 42 deletions(-) diff --git a/.gitignore b/.gitignore index b4f362eab..af2489b7f 100644 --- a/.gitignore +++ b/.gitignore @@ -34,3 +34,4 @@ metadata.json examples/javascript/node_modules examples/javascript/response.bin examples/javascript/package-lock.json +\#* diff --git a/libs/gl-client/src/lib.rs b/libs/gl-client/src/lib.rs index 08655d864..e17c825c2 100644 --- a/libs/gl-client/src/lib.rs +++ b/libs/gl-client/src/lib.rs @@ -61,6 +61,9 @@ use thiserror::Error; pub enum Error { #[error("The signature request does not match any authorized RPC calls")] MissingAuthorization, + + #[error("Illegal argument: {0}")] + IllegalArgument(String), } pub use lightning_signer::bitcoin; diff --git a/libs/gl-client/src/signer/auth.rs b/libs/gl-client/src/signer/auth.rs index 6ef17e4ab..04af2c690 100644 --- a/libs/gl-client/src/signer/auth.rs +++ b/libs/gl-client/src/signer/auth.rs @@ -19,16 +19,24 @@ impl Authorizer for GreenlightAuthorizer { &self, requests: &Vec, ) -> Result, Error> { - let approvals : Vec<_> = requests.iter().flat_map(|request| { + let mut approvals = Vec::new(); + for request in requests.iter() { match request { Request::Pay(req) => { - // TODO error handling - Some(Approval::Invoice(Invoice::from_str(&req.bolt11) - .expect(""))) + match Invoice::from_str(&req.bolt11) { + Ok(invoice) => { + approvals.push(Approval::Invoice(invoice)); + } + Err(e) => { + return Err(crate::Error::IllegalArgument( + format!("Failed to parse invoice from Pay request: {:?}", e) + )); + } + } } - _ => None, + _ => {} } - }).collect(); + } Ok(approvals) } } diff --git a/libs/gl-client/src/signer/mod.rs b/libs/gl-client/src/signer/mod.rs index 90fde12b7..4eb77e2e1 100644 --- a/libs/gl-client/src/signer/mod.rs +++ b/libs/gl-client/src/signer/mod.rs @@ -195,7 +195,9 @@ impl Signer { // we need for the rest of the run. let init = Signer::initmsg(&mut handler)?; - let init = HsmdInitReplyV4::from_vec(init).unwrap(); + let init = HsmdInitReplyV4::from_vec(init).map_err(|e| { + anyhow!("Failed to parse init message as HsmdInitReplyV4: {:?}", e) + })?; let id = init.node_id.0.to_vec(); use vls_protocol::msgs::SerBolt; @@ -235,7 +237,7 @@ impl Signer { fn handler(&self) -> Result { let mut h = self.init_handler()?; h.handle(Signer::initreq()) - .expect("handling the hsmd_init message"); + .map_err(|e| anyhow!("Failed to handle hsmd_init message: {:?}", e))?; Ok(h.into()) } @@ -253,7 +255,7 @@ impl Signer { .build() .map_err(|e| crate::signer::Error::Other(anyhow!("Could not create handler: {:?}", e)))?; h.handle(Signer::initreq()) - .expect("handling the hsmd_init message"); + .map_err(|e| Error::Other(anyhow!("Failed to handle hsmd_init message: {:?}", e)))?; Ok(h.into()) } @@ -276,12 +278,10 @@ impl Signer { } fn initmsg(handler: &mut vls_protocol_signer::handler::InitHandler) -> Result, Error> { - Ok(handler + let (_req, response) = handler .handle(Signer::initreq()) - .unwrap() - .1 - .map(|a| a.as_vec()) - .unwrap_or_default()) + .map_err(|e| Error::Other(anyhow!("Failed to handle init request: {:?}", e)))?; + Ok(response.map(|a| a.as_vec()).unwrap_or_default()) } /// Filter out any request that is not signed, such that the @@ -427,7 +427,7 @@ impl Signer { let signer_state = req.signer_state.clone(); trace!("Received request {}", hex_req); - match self.process_request(req).await { + match self.process_request(req.clone()).await { Ok(response) => { trace!("Sending response {}", hex::encode(&response.raw)); client @@ -436,6 +436,17 @@ impl Signer { .map_err(|e| Error::NodeDisconnect(e))?; } Err(e) => { + // Report the rejection to the server for debugging + // Note: process_request already reports some errors, but we ensure + // all errors are reported here as a safety net + report::Reporter::report(crate::pb::scheduler::SignerRejection { + msg: format!("Error in run_once loop: {:?}", e), + request: Some(req.clone()), + git_version: GITHASH.to_string(), + node_id: self.node_id(), + }) + .await; + let response = HsmResponse { raw: vec![], request_id, @@ -447,8 +458,8 @@ impl Signer { .await .map_err(|e| Error::NodeDisconnect(e))?; warn!( - "Ignoring error {} for request {} with state {:?}", - e, hex_req, signer_state, + "Rejected request {} with error: {}. State: {:?}", + hex_req, e, signer_state, ) } }; @@ -478,8 +489,12 @@ impl Signer { let prestate = { debug!("Updating local signer state with state from node"); - let mut state = self.state.lock().unwrap(); - state.merge(&diff).unwrap(); + let mut state = self.state.lock().map_err(|e| { + Error::Other(anyhow!("Failed to acquire state lock: {:?}", e)) + })?; + state.merge(&diff).map_err(|e| { + Error::Other(anyhow!("Failed to merge signer state: {:?}", e)) + })?; trace!("Processing request {}", hex::encode(&req.raw)); state.clone() }; @@ -512,7 +527,10 @@ impl Signer { let msg = vls_protocol::msgs::from_vec(req.raw.clone()).map_err(|e| Error::Protocol(e))?; log::debug!("Handling message {:?}", msg); - log::trace!("Signer state {}", serde_json::to_string(&prestate).unwrap()); + log::trace!( + "Signer state {}", + serde_json::to_string(&prestate).unwrap_or_else(|_| "".to_string()) + ); if let Err(e) = self.authenticate_request(&msg, &ctxrequests) { report::Reporter::report(crate::pb::scheduler::SignerRejection { @@ -580,7 +598,10 @@ impl Signer { root_handler.handle(msg) } Some(c) => { - let pk: [u8; 33] = c.node_id.try_into().unwrap(); + let node_id_len = c.node_id.len(); + let pk: [u8; 33] = c.node_id.try_into().map_err(|_| { + Error::Other(anyhow!("Invalid node_id length in context: expected 33 bytes, got {}", node_id_len)) + })?; let pk = vls_protocol::model::PubKey(pk); root_handler .for_new_client(1 as u64, pk, c.dbid) @@ -588,21 +609,25 @@ impl Signer { } }; - if let Err(e) = response { - report::Reporter::report(crate::pb::scheduler::SignerRejection { - msg: format!("{:?}", e), - request: Some(req.clone()), - git_version: GITHASH.to_string(), - node_id: self.node_id(), - }) - .await; - return Err(Error::Other(anyhow!("processing request: {e:?}"))); - } + let response = match response { + Ok(r) => r, + Err(e) => { + report::Reporter::report(crate::pb::scheduler::SignerRejection { + msg: format!("{:?}", e), + request: Some(req.clone()), + git_version: GITHASH.to_string(), + node_id: self.node_id(), + }) + .await; + return Err(Error::Other(anyhow!("processing request: {e:?}"))); + } + }; - let response = response.unwrap(); let signer_state: Vec = { debug!("Serializing state changes to report to node"); - let state = self.state.lock().unwrap(); + let state = self.state.lock().map_err(|e| { + Error::Other(anyhow!("Failed to acquire state lock for serialization: {:?}", e)) + })?; state.clone().into() }; Ok(HsmResponse { @@ -687,18 +712,30 @@ impl Signer { pub fn bip32_ext_key(&self) -> Vec { use vls_protocol::{msgs, msgs::Message}; - let initmsg = msgs::from_vec(self.init.clone()).expect("unparseable init message"); + // This should never fail since we validated it during construction + let initmsg = msgs::from_vec(self.init.clone()) + .expect("init message should be valid (validated during Signer::new)"); match initmsg { Message::HsmdInit2Reply(m) => m.bip32.0.to_vec(), Message::HsmdInitReplyV4(m) => m.bip32.0.to_vec(), Message::HsmdInitReplyV2(m) => m.bip32.0.to_vec(), - m => panic!("Unknown initmsg {:?}, cannot extract bip32 key", m), + m => { + // This should never happen, but log and return empty instead of panicking + error!("Unknown initmsg type {:?}, cannot extract bip32 key", m); + vec![] + } } } pub fn legacy_bip32_ext_key(&self) -> Vec { - let mut handler = self.init_handler().expect("retrieving the handler"); + let mut handler = match self.init_handler() { + Ok(h) => h, + Err(e) => { + error!("Failed to retrieve handler for legacy bip32 key: {:?}", e); + return vec![]; + } + }; let req = vls_protocol::msgs::Message::HsmdInit(vls_protocol::msgs::HsmdInit { key_version: vls_protocol::model::Bip32KeyVersion { pubkey_version: 0, @@ -714,13 +751,18 @@ impl Signer { hsm_wire_max_version: 2, }); - let initmsg = handler - .handle(req) - .expect("handling legacy init message") - .1 - .map(|a| a.as_vec()) - .unwrap_or_default(); + let initmsg = match handler.handle(req) { + Ok((_req, response)) => response.map(|a| a.as_vec()).unwrap_or_default(), + Err(e) => { + error!("Failed to handle legacy init message: {:?}", e); + return vec![]; + } + }; + if initmsg.len() <= 35 { + error!("Legacy init message too short: expected >35 bytes, got {}", initmsg.len()); + return vec![]; + } initmsg[35..].to_vec() }