From 4387fd1c03f4e42a32f038a10116b7fcd0a37a69 Mon Sep 17 00:00:00 2001 From: Olaoluwa Osuntokun Date: Wed, 21 Sep 2022 21:29:28 -0700 Subject: [PATCH] tarofreighter: add basic logging --- tarofreighter/chain_porter.go | 40 ++++++++++++++++++++++++++++++++++- tarofreighter/parcel.go | 4 ++++ 2 files changed, 43 insertions(+), 1 deletion(-) diff --git a/tarofreighter/chain_porter.go b/tarofreighter/chain_porter.go index 0969fabd4..14a4b24c6 100644 --- a/tarofreighter/chain_porter.go +++ b/tarofreighter/chain_porter.go @@ -95,8 +95,11 @@ func NewChainPorter(cfg *ChainPorterConfig) *ChainPorter { // Start kicks off the chain porter and any goroutines it needs to carry out // its duty. func (p *ChainPorter) Start() error { + var startErr error p.startOnce.Do(func() { + log.Infof("Starting ChainPorter") + // Before we re-launch the main goroutine, we'll make sure to // restart any other incomplete sends that may or may not have // had the transaction broadcaster. @@ -108,6 +111,9 @@ func (p *ChainPorter) Start() error { return } + log.Infof("Resuming delivery of %v pending asset parcels", + len(pendingParcels)) + // Now that we have the set of pending sends, we'll make a new // goroutine that'll drive the state machine till the broadcast // point (which we might be repeating), and final terminal @@ -141,6 +147,8 @@ func (p *ChainPorter) RequestShipment(req *AssetParcel) (*PendingParcel, error) req.errChan = make(chan error, 1) req.respChan = make(chan *PendingParcel, 1) + log.Infof("New asset shipment request to addr: %v", spew.Sdump(req)) + if !chanutils.SendOrQuit(p.exportReqs, req, p.Quit) { return nil, fmt.Errorf("ChainPorter shutting down") } @@ -164,6 +172,9 @@ func (p *ChainPorter) RequestShipment(req *AssetParcel) (*PendingParcel, error) // TODO(roasbeef): consolidate w/ below? or adopt similar arch as ChainPlanter // - could move final conf into the state machien itself func (p *ChainPorter) resumePendingParcel(pkg *OutboundParcelDelta) { + log.Infof("Attempting to resume delivery to anchor_point=%v", + pkg.NewAnchorPoint) + // To resume the state machine, we'll make a skeleton of a sendPackage, // basically just what we need to drive the state machine to further // completion. @@ -194,6 +205,10 @@ func (p *ChainPorter) taroPorter() { for { select { case req := <-p.exportReqs: + log.Infof("Received to send request to: %x:%x", + req.Dest.ID(), + req.Dest.ScriptKey.SerializeCompressed()) + // Initialize a package with the destination address. sendPkg := sendPackage{ ReceiverAddr: req.Dest, @@ -243,6 +258,10 @@ func (p *ChainPorter) waitForPkgConfirmation(pkg *OutboundParcelDelta) { return fmt.Errorf(format, args...) } + txHash := pkg.AnchorTx.TxHash() + + log.Infof("Waiting for confirmation of transfer_txid=%v", txHash) + // Before we can broadcast, we want to find out the current height to // pass as a height hint. currentHeight, err := p.cfg.ChainBridge.CurrentHeight(ctx) @@ -251,7 +270,6 @@ func (p *ChainPorter) waitForPkgConfirmation(pkg *OutboundParcelDelta) { return } - txHash := pkg.AnchorTx.TxHash() confCtx, confCancel := p.WithCtxQuit() confNtfn, errChan, err := p.cfg.ChainBridge.RegisterConfirmationsNtfn( confCtx, &txHash, pkg.AnchorTx.TxOut[0].PkScript, 1, @@ -355,6 +373,8 @@ func (p *ChainPorter) waitForPkgConfirmation(pkg *OutboundParcelDelta) { return } + log.Infof("Importing receiver proof into local Proof Archive") + // Now we'll write out the final receiver proof to the on disk proof // archive. var updatedReceiverProof bytes.Buffer @@ -522,6 +542,10 @@ func (p *ChainPorter) stateStep(currentPkg sendPackage) (*sendPackage, error) { return nil, err } + log.Infof("Selected %v possible asset inputs for send to %x", + len(elgigibleCommitments), + currentPkg.ReceiverAddr.ScriptKey.SerializeCompressed()) + // We'll take just the first commitment here as we need enough // to complete the send w/o merging inputs. assetInput := elgigibleCommitments[0] @@ -641,6 +665,9 @@ func (p *ChainPorter) stateStep(currentPkg sendPackage) (*sendPackage, error) { // At this point, we have everything we need to sign our _virtual_ // transaction on the Taro layer. case SendStateSigned: + log.Infof("Generating Taro witnesses for send to: %x", + currentPkg.ReceiverAddr.ScriptKey.SerializeCompressed()) + // Now we'll use the signer to sign all the inputs for the new // taro leaves. The witness data for each input will be // assigned for us. @@ -673,6 +700,9 @@ func (p *ChainPorter) stateStep(currentPkg sendPackage) (*sendPackage, error) { return nil, err } + log.Infof("Constructing new Taro commitments for send to: %x", + currentPkg.ReceiverAddr.ScriptKey.SerializeCompressed()) + currentPkg.NewOutputCommitments = spendCommitments // Otherwise, we can go straight to stamping things as we have @@ -727,6 +757,9 @@ func (p *ChainPorter) stateStep(currentPkg sendPackage) (*sendPackage, error) { int64(currentPkg.InputAsset.AnchorOutputValue), ) + log.Infof("Received funded PSBT packet: %v", + spew.Sdump(fundedSendPacket.Pkt)) + currentPkg.SendPkt = fundedSendPacket.Pkt currentPkg.SendState = SendStatePsbtSign @@ -876,6 +909,8 @@ func (p *ChainPorter) stateStep(currentPkg sendPackage) (*sendPackage, error) { ctx, cancel := p.CtxBlocking() defer cancel() + log.Infof("Committing pending parcel to disk") + err = p.cfg.ExportLog.LogPendingParcel( ctx, currentPkg.OutboundPkg, ) @@ -923,6 +958,9 @@ func (p *ChainPorter) stateStep(currentPkg sendPackage) (*sendPackage, error) { return nil, err } + log.Infof("Broadcasting new transfer tx, taro_anchor_output=%x", + spew.Sdump(anchorOutput)) + // With the public key imported, we can now broadcast to the // network. err = p.cfg.ChainBridge.PublishTransaction( diff --git a/tarofreighter/parcel.go b/tarofreighter/parcel.go index c551ce3fa..dc5ee5369 100644 --- a/tarofreighter/parcel.go +++ b/tarofreighter/parcel.go @@ -418,6 +418,10 @@ func (s *sendPackage) createProofs() (spendProofs, error) { func (s *sendPackage) deliverResponse(respChan chan<- *PendingParcel) { oldRoot := s.InputAsset.Commitment.TapscriptRoot(nil) + log.Infof("Outbound parcel now pending for %x:%x, delivering "+ + "notification", s.ReceiverAddr.ID(), + s.ReceiverAddr.ScriptKey.SerializeCompressed()) + respChan <- &PendingParcel{ NewAnchorPoint: s.OutboundPkg.NewAnchorPoint, TransferTx: s.OutboundPkg.AnchorTx,