diff --git a/channelAcceptor.go b/channelAcceptor.go index 9a4fbe9..62ba128 100644 --- a/channelAcceptor.go +++ b/channelAcceptor.go @@ -104,9 +104,19 @@ func (app *App) interceptChannelEvents(ctx context.Context) error { ) } + contextLogger := log.WithFields(log.Fields{ + "event": "channel_request", + "amount": req.FundingAmt, + "alias": alias, + "pubkey": hex.EncodeToString(req.NodePubkey), + "pending_chan_id": hex.EncodeToString(req.PendingChanId), + "total_capacity": info.TotalCapacity, + "num_channels": info.NumChannels, + }) + res := lnrpc.ChannelAcceptResponse{} if accept { - log.Infof("[channel] ✅ Allow channel %s", channel_info_string) + contextLogger.Infof("[channel] ✅ Allow channel %s", channel_info_string) res = lnrpc.ChannelAcceptResponse{Accept: true, PendingChanId: req.PendingChanId, CsvDelay: req.CsvDelay, @@ -117,7 +127,7 @@ func (app *App) interceptChannelEvents(ctx context.Context) error { } } else { - log.Infof("[channel] ❌ Deny channel %s", channel_info_string) + contextLogger.Infof("[channel] ❌ Deny channel %s", channel_info_string) res = lnrpc.ChannelAcceptResponse{Accept: false, Error: Configuration.ChannelRejectMessage} } @@ -150,7 +160,14 @@ func (app *App) logChannelEvents(ctx context.Context) error { event.GetOpenChannel().Capacity, alias, ) - log.Infof("[channel] Opened channel %s %s", ParseChannelID(event.GetOpenChannel().ChanId), channel_info_string) + contextLogger := log.WithFields(log.Fields{ + "event": "channel_open", + "capacity": event.GetOpenChannel().Capacity, + "alias": alias, + "pubkey": event.GetOpenChannel().RemotePubkey, + "chan_id": ParseChannelID(event.GetOpenChannel().ChanId), + }) + contextLogger.Infof("[channel] Opened channel %s %s", ParseChannelID(event.GetOpenChannel().ChanId), channel_info_string) } log.Tracef("[channel] Event: %s", event.String()) } diff --git a/config.go b/config.go index 5bcb7a8..5b4603a 100644 --- a/config.go +++ b/config.go @@ -13,6 +13,7 @@ var Configuration = struct { MacaroonPath string `yaml:"macaroon_path"` TLSPath string `yaml:"tls-path"` Debug bool `yaml:"debug"` + LogMode string `yaml:"log-mode"` ChannelAllowlist []string `yaml:"channel-allowlist"` ChannelDenylist []string `yaml:"channel-denylist"` ChannelRejectMessage string `yaml:"channel-reject-message"` @@ -30,7 +31,7 @@ func init() { } func checkConfig() { - setLogger(Configuration.Debug) + setLogger(Configuration.Debug, Configuration.LogMode == "json") welcome() if Configuration.Host == "" { diff --git a/config.yaml.example b/config.yaml.example index bf1a936..e96b773 100644 --- a/config.yaml.example +++ b/config.yaml.example @@ -7,6 +7,8 @@ host: "127.0.0.1:10009" macaroon_path: "/home/bitcoin/.lnd/data/chain/bitcoin/mainnet/admin.macaroon" tls-path: "/home/bitcoin/.lnd/tls.cert" debug: true +# to get only json output +# log-mode: "json" # ----- Channel openings ----- diff --git a/helpers.go b/helpers.go index 64e61b3..3ac3ed3 100644 --- a/helpers.go +++ b/helpers.go @@ -5,6 +5,7 @@ import ( "encoding/hex" "fmt" "math/big" + "os" "strconv" log "github.com/sirupsen/logrus" @@ -20,11 +21,17 @@ func trimPubKey(pubkey []byte) string { } func welcome() { - log.Info("---- ⚡️ electronwall 0.3.2 ⚡️ ----") + log.Info("---- ⚡️ electronwall 0.3.3 ⚡️ ----") } // setLogger will initialize the log format -func setLogger(debug bool) { +func setLogger(debug bool, json bool) { + if json { + log.SetFormatter(&log.JSONFormatter{}) + return + } + + log.SetOutput(os.Stdout) if debug { log.SetLevel(log.DebugLevel) } else { @@ -33,6 +40,8 @@ func setLogger(debug bool) { customFormatter := new(log.TextFormatter) customFormatter.TimestampFormat = "2006-01-02 15:04:05" customFormatter.FullTimestamp = true + customFormatter.ForceColors = true + log.SetFormatter(customFormatter) } @@ -55,76 +64,3 @@ func ParseChannelID(e uint64) string { int_block1, _ := strconv.ParseInt(hexstr[12:], 16, 64) return fmt.Sprintf("%dx%dx%d", int_block3, int_block2, int_block1) } - -// These functions are inspired by by Joost Jager's circuitbreaker - -// // getNodeInfo returns the information of a node given a pubKey -// func (app *App) getNodeInfo(ctx context.Context, pubkey string) (nodeInfo *lnrpc.NodeInfo, err error) { -// ctx, cancel := context.WithTimeout(ctx, 10*time.Second) -// defer cancel() - -// info, err := app.client.GetNodeInfo(ctx, &lnrpc.NodeInfoRequest{ -// PubKey: pubkey, -// }) -// if err != nil { -// return &lnrpc.NodeInfo{}, err -// } -// return info, nil -// } - -// // getNodeAlias returns the alias of a node pubkey -// func (app *App) getNodeAlias(ctx context.Context, pubkey string) (string, error) { -// info, err := app.getNodeInfo(ctx, pubkey) -// if err != nil { -// return "", err -// } - -// if info.Node == nil { -// return "", errors.New("node info not available") -// } -// return info.Node.Alias, nil -// } - -// // getMyPubkey returns the pubkey of my own node -// func (app *App) getMyInfo(ctx context.Context) (*lnrpc.GetInfoResponse, error) { -// ctx, cancel := context.WithTimeout(ctx, 10*time.Second) -// defer cancel() - -// info, err := app.client.GetInfo(ctx, &lnrpc.GetInfoRequest{}) -// if err != nil { -// return &lnrpc.GetInfoResponse{}, err -// } -// return info, nil -// } - -// type channelEdge struct { -// node1Pub, node2Pub route.Vertex -// } - -// // getPubKeyFromChannel returns the pubkey of the remote node in a channel -// func (app *App) getPubKeyFromChannel(ctx context.Context, chan_id uint64) (*channelEdge, error) { -// ctx, cancel := context.WithTimeout(ctx, 10*time.Second) -// defer cancel() - -// info, err := app.client.GetChanInfo(ctx, &lnrpc.ChanInfoRequest{ -// ChanId: chan_id, -// }) -// if err != nil { -// return nil, err -// } - -// node1Pub, err := route.NewVertexFromStr(info.Node1Pub) -// if err != nil { -// return nil, err -// } - -// node2Pub, err := route.NewVertexFromStr(info.Node2Pub) -// if err != nil { -// return nil, err -// } - -// return &channelEdge{ -// node1Pub: node1Pub, -// node2Pub: node2Pub, -// }, nil -// } diff --git a/htlcInterceptor.go b/htlcInterceptor.go index 50e1740..99fb3c5 100644 --- a/htlcInterceptor.go +++ b/htlcInterceptor.go @@ -2,6 +2,7 @@ package main import ( "context" + "encoding/hex" "fmt" "strings" "sync" @@ -84,6 +85,7 @@ func (app *App) interceptHtlcEvents(ctx context.Context) error { } log.Tracef("[forward] HTLC event (%d->%d)", event.IncomingCircuitKey.ChanId, event.OutgoingRequestedChanId) + forward_info_string := fmt.Sprintf( "from %s to %s (%d sat, chan_id:%s->%s, htlc_id:%d)", aliasFrom, @@ -97,11 +99,22 @@ func (app *App) interceptHtlcEvents(ctx context.Context) error { response := &routerrpc.ForwardHtlcInterceptResponse{ IncomingCircuitKey: event.IncomingCircuitKey, } + + contextLogger := log.WithFields(log.Fields{ + "event": "forward_request", + "in_alias": aliasFrom, + "out_alias": aliasTo, + "amount": event.IncomingAmountMsat / 1000, + "in_chan_id": ParseChannelID(event.IncomingCircuitKey.ChanId), + "out_chan_id": ParseChannelID(event.OutgoingRequestedChanId), + "htlc_id": event.IncomingCircuitKey.HtlcId, + }) + if <-decision_chan { - log.Infof("[forward] ✅ Allow HTLC %s", forward_info_string) + contextLogger.Infof("[forward] ✅ Allow HTLC %s", forward_info_string) response.Action = routerrpc.ResolveHoldForwardAction_RESUME } else { - log.Infof("[forward] ❌ Deny HTLC %s", forward_info_string) + contextLogger.Infof("[forward] ❌ Deny HTLC %s", forward_info_string) response.Action = routerrpc.ResolveHoldForwardAction_FAIL } err = interceptor.Send(response) @@ -123,6 +136,9 @@ func (app *App) htlcInterceptDecision(ctx context.Context, event *routerrpc.Forw var accept bool var listToParse []string + // // sleep for 60 seconds + // time.Sleep(60 * time.Second) + // determine filtering mode and list to parse switch Configuration.ForwardMode { case "allowlist": @@ -181,18 +197,29 @@ func (app *App) logHtlcEvents(ctx context.Context) error { continue } + contextLogger := log.WithFields(log.Fields{ + "event": "forward_event", + "chan_id": ParseChannelID(event.IncomingChannelId), + "htlc_id": event.IncomingHtlcId, + }) + switch event.Event.(type) { case *routerrpc.HtlcEvent_SettleEvent: - log.Debugf("[forward] ⚡️ HTLC SettleEvent (chan_id:%s, htlc_id:%d)", ParseChannelID(event.IncomingChannelId), event.IncomingHtlcId) + contextLogger.Infof("[forward] ⚡️ HTLC SettleEvent") + log.Debugf("[forward] Preimage: %s", hex.EncodeToString(event.GetSettleEvent().Preimage)) case *routerrpc.HtlcEvent_ForwardFailEvent: - log.Debugf("[forward] HTLC ForwardFailEvent (chan_id:%s, htlc_id:%d)", ParseChannelID(event.IncomingChannelId), event.IncomingHtlcId) + contextLogger.Infof("[forward] HTLC ForwardFailEvent") + log.Debugf("[forward] Reason: %s", event.GetForwardFailEvent().String()) case *routerrpc.HtlcEvent_ForwardEvent: - log.Debugf("[forward] HTLC ForwardEvent (chan_id:%s, htlc_id:%d)", ParseChannelID(event.IncomingChannelId), event.IncomingHtlcId) + contextLogger.Infof("[forward] HTLC ForwardEvent") + // log.Infof("[forward] HTLC ForwardEvent (chan_id:%s, htlc_id:%d)", ParseChannelID(event.IncomingChannelId), event.IncomingHtlcId) + // log.Debugf("[forward] Details: %s", event.GetForwardEvent().String()) case *routerrpc.HtlcEvent_LinkFailEvent: - log.Debugf("[forward] HTLC LinkFailEvent (chan_id:%s, htlc_id:%d)", ParseChannelID(event.IncomingChannelId), event.IncomingHtlcId) + contextLogger.Infof("[forward] HTLC LinkFailEvent") + log.Debugf("[forward] Reason: %s", event.GetLinkFailEvent().FailureString) } }