Add debug logging to gRPC entrypoints

This additional logging may help with debugging lightwalletd clients as
it may isolate the problem to the client or server (lightwalletd) side.

To see entrypoint logging, you must start lightwalletd with the option
--log-level 5 (which is "debug"; the default is 4, which is "info")).

This option shouldn't be used in normal operation, because clients could
flood the log, causing crashes due to running out of disk space. Only
use this when actually debugging or testing.

For most gRPCs, also log return values if the log-level is 6 ("trace").
Return value logging isn't done if there is an error (it's assumed that
the client will log something) or if the output might be very large (we
don't want to overrun the log file).

Enabling trace (--log-level 6) enables everything below that level,
so entry logging is enabled as well.
This commit is contained in:
Larry Ruane 2024-08-12 17:00:55 -06:00 committed by Larry Ruane
parent a9e47fd37e
commit 7ec4d1c67c
1 changed files with 52 additions and 10 deletions

View File

@ -60,6 +60,7 @@ func checkTaddress(taddr string) error {
// GetLatestBlock returns the height and hash of the best chain, according to zcashd.
func (s *lwdStreamer) GetLatestBlock(ctx context.Context, placeholder *walletrpc.ChainSpec) (*walletrpc.BlockID, error) {
common.Log.Debugf("gRPC GetLatestBlock(%+v)\n", placeholder)
// Lock to ensure we return consistent height and hash
s.mutex.Lock()
defer s.mutex.Unlock()
@ -71,13 +72,16 @@ func (s *lwdStreamer) GetLatestBlock(ctx context.Context, placeholder *walletrpc
if err != nil {
return nil, err
}
return &walletrpc.BlockID{Height: uint64(blockChainInfo.Blocks), Hash: []byte(bestBlockHash)}, nil
r := &walletrpc.BlockID{Height: uint64(blockChainInfo.Blocks), Hash: []byte(bestBlockHash)}
common.Log.Tracef(" return: %+v\n", r)
return r, nil
}
// GetTaddressTxids is a streaming RPC that returns transactions that have
// the given transparent address (taddr) as either an input or output.
// NB, this method is misnamed, it does not return txids.
func (s *lwdStreamer) GetTaddressTxids(addressBlockFilter *walletrpc.TransparentAddressBlockFilter, resp walletrpc.CompactTxStreamer_GetTaddressTxidsServer) error {
common.Log.Debugf("gRPC GetTaddressTxids(%+v)\n", addressBlockFilter)
if err := checkTaddress(addressBlockFilter.Address); err != nil {
return err
}
@ -137,6 +141,7 @@ func (s *lwdStreamer) GetTaddressTxids(addressBlockFilter *walletrpc.Transparent
// GetBlock returns the compact block at the requested height. Requesting a
// block by hash is not yet supported.
func (s *lwdStreamer) GetBlock(ctx context.Context, id *walletrpc.BlockID) (*walletrpc.CompactBlock, error) {
common.Log.Debugf("gRPC GetBlock(%+v)\n", id)
if id.Height == 0 && id.Hash == nil {
return nil, errors.New("request for unspecified identifier")
}
@ -152,12 +157,14 @@ func (s *lwdStreamer) GetBlock(ctx context.Context, id *walletrpc.BlockID) (*wal
if err != nil {
return nil, err
}
common.Log.Tracef(" return: %+v\n", cBlock)
return cBlock, err
}
// GetBlockNullifiers is the same as GetBlock except that it returns the compact block
// with actions containing only the nullifiers (a subset of the full compact block).
func (s *lwdStreamer) GetBlockNullifiers(ctx context.Context, id *walletrpc.BlockID) (*walletrpc.CompactBlock, error) {
common.Log.Debugf("gRPC GetBlockNullifiers(%+v)\n", id)
if id.Height == 0 && id.Hash == nil {
return nil, errors.New("request for unspecified identifier")
}
@ -182,6 +189,7 @@ func (s *lwdStreamer) GetBlockNullifiers(ctx context.Context, id *walletrpc.Bloc
// these are not needed (we prefer to save bandwidth)
cBlock.ChainMetadata.SaplingCommitmentTreeSize = 0
cBlock.ChainMetadata.OrchardCommitmentTreeSize = 0
common.Log.Tracef(" return: %+v\n", cBlock)
return cBlock, err
}
@ -189,6 +197,7 @@ func (s *lwdStreamer) GetBlockNullifiers(ctx context.Context, id *walletrpc.Bloc
// (as also returned by GetBlock) from the block height 'start' to height
// 'end' inclusively.
func (s *lwdStreamer) GetBlockRange(span *walletrpc.BlockRange, resp walletrpc.CompactTxStreamer_GetBlockRangeServer) error {
common.Log.Debugf("gRPC GetBlockRange(%+v)\n", span)
blockChan := make(chan *walletrpc.CompactBlock)
if span.Start == nil || span.End == nil {
return errors.New("must specify start and end heights")
@ -213,6 +222,7 @@ func (s *lwdStreamer) GetBlockRange(span *walletrpc.BlockRange, resp walletrpc.C
// GetBlockRangeNullifiers is the same as GetBlockRange except that only
// the actions contain only nullifiers (a subset of the full compact block).
func (s *lwdStreamer) GetBlockRangeNullifiers(span *walletrpc.BlockRange, resp walletrpc.CompactTxStreamer_GetBlockRangeNullifiersServer) error {
common.Log.Debugf("gRPC GetBlockRangeNullifiers(%+v)\n", span)
blockChan := make(chan *walletrpc.CompactBlock)
if span.Start == nil || span.End == nil {
return errors.New("must specify start and end heights")
@ -258,10 +268,13 @@ func (s *lwdStreamer) GetTreeState(ctx context.Context, id *walletrpc.BlockID) (
if err != nil {
return nil, err
}
common.Log.Debugf("gRPC GetTreeState(height=%+v)\n", id.Height)
params[0] = heightJSON
} else {
// id.Hash is big-endian, keep in big-endian for the rpc
hashJSON, err := json.Marshal(hex.EncodeToString(id.Hash))
hash := hex.EncodeToString(id.Hash)
common.Log.Debugf("gRPC GetTreeState(hash=%+v)\n", hash)
hashJSON, err := json.Marshal(hash)
if err != nil {
return nil, err
}
@ -292,28 +305,36 @@ func (s *lwdStreamer) GetTreeState(ctx context.Context, id *walletrpc.BlockID) (
if gettreestateReply.Sapling.Commitments.FinalState == "" {
return nil, errors.New(common.NodeName + " did not return treestate")
}
return &walletrpc.TreeState{
r := &walletrpc.TreeState{
Network: s.chainName,
Height: uint64(gettreestateReply.Height),
Hash: gettreestateReply.Hash,
Time: gettreestateReply.Time,
SaplingTree: gettreestateReply.Sapling.Commitments.FinalState,
OrchardTree: gettreestateReply.Orchard.Commitments.FinalState,
}, nil
}
common.Log.Tracef(" return: %+v\n", r)
return r, nil
}
func (s *lwdStreamer) GetLatestTreeState(ctx context.Context, in *walletrpc.Empty) (*walletrpc.TreeState, error) {
common.Log.Debugf("gRPC GetLatestTreeState()\n")
blockChainInfo, err := common.GetBlockChainInfo()
if err != nil {
return nil, err
}
latestHeight := blockChainInfo.Blocks
return s.GetTreeState(ctx, &walletrpc.BlockID{Height: uint64(latestHeight)})
r, err := s.GetTreeState(ctx, &walletrpc.BlockID{Height: uint64(latestHeight)})
if err == nil {
common.Log.Tracef(" return: %+v\n", r)
}
return r, err
}
// GetTransaction returns the raw transaction bytes that are returned
// by the zcashd 'getrawtransaction' RPC.
func (s *lwdStreamer) GetTransaction(ctx context.Context, txf *walletrpc.TxFilter) (*walletrpc.RawTransaction, error) {
common.Log.Debugf("gRPC GetTransaction(%+v)\n", txf)
if txf.Hash != nil {
if len(txf.Hash) != 32 {
return nil, errors.New("transaction ID has invalid length")
@ -330,7 +351,11 @@ func (s *lwdStreamer) GetTransaction(ctx context.Context, txf *walletrpc.TxFilte
return nil, rpcErr
}
return common.ParseRawTransaction(result)
r, err := common.ParseRawTransaction(result)
if err == nil {
common.Log.Tracef(" return: %+v\n", r)
}
return r, nil
}
if txf.Block != nil && txf.Block.Hash != nil {
@ -347,6 +372,7 @@ func (s *lwdStreamer) GetLightdInfo(ctx context.Context, in *walletrpc.Empty) (*
// SendTransaction forwards raw transaction bytes to a zcashd instance over JSON-RPC
func (s *lwdStreamer) SendTransaction(ctx context.Context, rawtx *walletrpc.RawTransaction) (*walletrpc.SendResponse, error) {
common.Log.Debugf("gRPC SendTransaction(%+v)\n", rawtx)
// sendrawtransaction "hexstring" ( allowhighfees )
//
// Submits raw transaction (binary) to local node and network.
@ -391,10 +417,12 @@ func (s *lwdStreamer) SendTransaction(ctx context.Context, rawtx *walletrpc.RawT
// TODO these are called Error but they aren't at the moment.
// A success will return code 0 and message txhash.
return &walletrpc.SendResponse{
r := &walletrpc.SendResponse{
ErrorCode: int32(errCode),
ErrorMessage: errMsg,
}, nil
}
common.Log.Tracef(" return: %+v\n", r)
return r, nil
}
func getTaddressBalanceZcashdRpc(addressList []string) (*walletrpc.Balance, error) {
@ -427,11 +455,17 @@ func getTaddressBalanceZcashdRpc(addressList []string) (*walletrpc.Balance, erro
// GetTaddressBalance returns the total balance for a list of taddrs
func (s *lwdStreamer) GetTaddressBalance(ctx context.Context, addresses *walletrpc.AddressList) (*walletrpc.Balance, error) {
return getTaddressBalanceZcashdRpc(addresses.Addresses)
common.Log.Debugf("gRPC GetTaddressBalance(%+v)\n", addresses)
r, err := getTaddressBalanceZcashdRpc(addresses.Addresses)
if err == nil {
common.Log.Tracef(" return: %+v\n", r)
}
return r, err
}
// GetTaddressBalanceStream returns the total balance for a list of taddrs
func (s *lwdStreamer) GetTaddressBalanceStream(addresses walletrpc.CompactTxStreamer_GetTaddressBalanceStreamServer) error {
common.Log.Debugf("gRPC GetTaddressBalanceStream(%+v)\n", addresses)
addressList := make([]string, 0)
for {
addr, err := addresses.Recv()
@ -448,10 +482,12 @@ func (s *lwdStreamer) GetTaddressBalanceStream(addresses walletrpc.CompactTxStre
return err
}
addresses.SendAndClose(balance)
common.Log.Tracef(" return: %+v\n", balance)
return nil
}
func (s *lwdStreamer) GetMempoolStream(_empty *walletrpc.Empty, resp walletrpc.CompactTxStreamer_GetMempoolStreamServer) error {
common.Log.Debugf("gRPC GetMempoolStream()\n")
err := common.GetMempool(func(tx *walletrpc.RawTransaction) error {
return resp.Send(tx)
})
@ -466,6 +502,7 @@ var mempoolList []string
var lastMempool time.Time
func (s *lwdStreamer) GetMempoolTx(exclude *walletrpc.Exclude, resp walletrpc.CompactTxStreamer_GetMempoolTxServer) error {
common.Log.Debugf("gRPC GetMempoolTx(%+v)\n", exclude)
s.mutex.Lock()
defer s.mutex.Unlock()
@ -654,6 +691,7 @@ func getAddressUtxos(arg *walletrpc.GetAddressUtxosArg, f func(*walletrpc.GetAdd
}
func (s *lwdStreamer) GetAddressUtxos(ctx context.Context, arg *walletrpc.GetAddressUtxosArg) (*walletrpc.GetAddressUtxosReplyList, error) {
common.Log.Debugf("gRPC GetAddressUtxos(%+v)\n", arg)
addressUtxos := make([]*walletrpc.GetAddressUtxosReply, 0)
err := getAddressUtxos(arg, func(utxo *walletrpc.GetAddressUtxosReply) error {
addressUtxos = append(addressUtxos, utxo)
@ -662,10 +700,13 @@ func (s *lwdStreamer) GetAddressUtxos(ctx context.Context, arg *walletrpc.GetAdd
if err != nil {
return &walletrpc.GetAddressUtxosReplyList{}, err
}
return &walletrpc.GetAddressUtxosReplyList{AddressUtxos: addressUtxos}, nil
r := &walletrpc.GetAddressUtxosReplyList{AddressUtxos: addressUtxos}
common.Log.Tracef(" return: %+v\n", r)
return r, nil
}
func (s *lwdStreamer) GetSubtreeRoots(arg *walletrpc.GetSubtreeRootsArg, resp walletrpc.CompactTxStreamer_GetSubtreeRootsServer) error {
common.Log.Debugf("gRPC GetSubtreeRoots(%+v)\n", arg)
if common.DarksideEnabled {
return common.DarksideGetSubtreeRoots(arg, resp)
}
@ -729,6 +770,7 @@ func (s *lwdStreamer) GetSubtreeRoots(arg *walletrpc.GetSubtreeRootsArg, resp wa
}
func (s *lwdStreamer) GetAddressUtxosStream(arg *walletrpc.GetAddressUtxosArg, resp walletrpc.CompactTxStreamer_GetAddressUtxosStreamServer) error {
common.Log.Debugf("gRPC GetAddressUtxosStream(%+v)\n", arg)
err := getAddressUtxos(arg, func(utxo *walletrpc.GetAddressUtxosReply) error {
return resp.Send(utxo)
})