A draft script to clean itest logs for lnd

main.go

package main

import (
	"fmt"
	"io/ioutil"
	"os"
	"sort"
	"strings"
	"time"
)

func split(r rune) bool {
	return r == '=' || r == ' ' || r == ',' || r == '-'
}

// node represents a peer extracted from the logs.
type node struct {
	name       string
	suffix     string
	pubKey     string
	testName   string
	logpath    string
	newLogpath string
}

// extractFilename creates a node by extracting info from the log's filename. A
// log's filename has the format, `nodeID-testName-nodeName-pubKey.log`, for
// instance,
//   - 0-forward_interceptor-Alice-0256c916.log
//
// will be extracted as,
//   - name: Alice
//   - suffix: 0256c916
//   - testName: forward_interceptor
func extractFilename(filename, logDir, newLogDir string) (*node, error) {
	// Split the string by `-` should give us at least 4 items.
	data := strings.Split(filename, "-")
	if len(data) < 4 {
		return nil, fmt.Errorf("found unexpected file: %s", filename)
	}

	num := len(data)

	// Extract node name, test name and public key suffix.
	nodeName, suffix := data[num-2], data[num-1]
	testName := strings.Join(data[1:num], "-")

	// Suffix is now "pubKey.log".
	suffixes := strings.Split(suffix, ".")
	if len(suffixes) != 2 || suffixes[1] != "log" {
		return nil, fmt.Errorf("found file not ending with '.log': %s",
			filename)
	}

	pubKeySuffix := suffixes[0]
	filepath := fmt.Sprintf("%s/%s", logDir, filename)
	newFilepath := fmt.Sprintf("%s/%s_%s_%s.log", newLogDir, data[0],
		testName, nodeName)

	return &node{
		name:       nodeName,
		suffix:     pubKeySuffix,
		testName:   data[1],
		logpath:    filepath,
		newLogpath: newFilepath,
	}, nil
}

// extractPubKeys reads the log line to find the full public key.
func extractPubKeys(line, suffix string) string {
	// Check the line contains the suffix.
	if strings.Contains(line, suffix) {
		// We may sometimes get "pubKey@address", so we split to only
		// grab the pubKey part.
		line = strings.Split(line, "@")[0]
		words := strings.FieldsFunc(line, split)
		for _, w := range words {
			if strings.HasPrefix(w, suffix) {
				return w
			}
		}
	}

	return ""
}

// extractChannelPointFrom reads the following log to extract the funding
// outpoint from the sender side,
// [DBG] PEER: Peer(pubKey): Sending MsgFundingCreated(temp_chan_id=, chan_point=) to pubKey@address.
func extractChannelPointFrom(line string) string {
	token := ": Sending MsgFundingCreated"
	if strings.Contains(line, token) {
		words := strings.Split(line, token)
		word := strings.Split(words[1], "chan_point=")[1]
		cp := strings.Split(word, ")")[0]
		return cp
	}

	return ""
}

// extractChannelPointFrom reads the following log to extract the funding
// outpoint from the receiver side,
func extractChannelPointTo(line string) string {
	token := ": Received MsgFundingCreated"
	if strings.Contains(line, token) {
		words := strings.Split(line, token)
		word := strings.Split(words[1], "chan_point=")[1]
		cp := strings.Split(word, ")")[0]
		return cp
	}

	return ""
}

// 2022-11-03 10:41:23.999 [DBG] FNDG: Will announce channel 622323581648896 after ChannelPoint(a9ba0534c7155c55018c5900833d136cedc1c5f576cdf72d702333777856fb4e:0) has gotten 6 confirmations
func extractShortChanID(line string) (string, string) {
	token := "Will announce channel "
	if strings.Contains(line, token) {
		words := strings.Split(line, token)
		// words[1]:
		// 622323581648896 after ChannelPoint(a9ba0534c7155c55018c5900833d136cedc1c5f576cdf72d702333777856fb4e:0) has gotten 6 confirmations
		words = strings.Split(words[1], " after ")
		sid := words[0]
		// ChannelPoint(a9ba0534c7155c55018c5900833d136cedc1c5f576cdf72d702333777856fb4e:0)
		cp_part := strings.Split(words[1], "(")[1]
		cp := strings.Split(cp_part, ")")[0]

		return sid, cp
	}

	return "", ""
}

func main() {
	// First element in os.Args is always the program name, So we need at
	// least 2 arguments to have a file name argument.
	if len(os.Args) < 2 {
		fmt.Println("Missing parameter, provide file path!")
		return
	}

	logDir := os.Args[1]

	files, err := ioutil.ReadDir(logDir)
	if err != nil {
		fmt.Println(err)
	}

	newLogDir := fmt.Sprintf("%s/cleaned", logDir)
	if err := os.MkdirAll(newLogDir, os.ModePerm); err != nil {
		fmt.Println("creating dir got err:", err)
		return
	}

	// First, iterate all files to get the public key suffix and log
	// filepaths.
	nodes := make([]*node, 0)
	for _, file := range files {
		if file.IsDir() {
			continue
		}

		if strings.Contains(file.Name(), "chainbackend.log") {
			continue
		}

		if strings.Contains(file.Name(), "miner.log") {
			continue
		}

		// Get public key suffix, filepath and new filepath from the
		// filename.
		node, err := extractFilename(file.Name(), logDir, newLogDir)
		if err != nil {
			fmt.Printf("invalid filename: %v\n", err)
			continue
		}
		nodes = append(nodes, node)
	}

	newFiles := make(map[string]string)

	// Now go through each node, read its log and find the full public key.
	for _, node := range nodes {
		// Read the logs into a buffer.
		// fmt.Println(node.logpath)
		input, err := ioutil.ReadFile(node.logpath)
		if err != nil {
			fmt.Printf("reading filepath %s got: %v",
				node.logpath, err)
			return
		}
		logs := string(input)
		lines := strings.Split(logs, "\n")

		// Find public keys.
		for _, n := range nodes {
			for _, line := range lines {
				pubKey := extractPubKeys(line, n.suffix)
				if pubKey != "" {
					n.pubKey = pubKey
					break
				}
			}
		}
		newFiles[node.newLogpath] = logs
	}

	type channelInfo struct {
		shortChanID string
		from        *node
		to          *node
	}

	channels := make(map[string]*channelInfo)
	for _, node := range nodes {
		lines := strings.Split(newFiles[node.newLogpath], "\n")

		for _, line := range lines {
			cp := extractChannelPointFrom(line)
			if cp != "" {
				chanInfo, ok := channels[cp]
				if !ok {
					chanInfo = &channelInfo{
						from: node,
					}
					channels[cp] = chanInfo
				} else {
					chanInfo.from = node
				}
			}

			cp = extractChannelPointTo(line)
			if cp != "" {
				chanInfo, ok := channels[cp]
				if !ok {
					chanInfo = &channelInfo{
						to: node,
					}
					channels[cp] = chanInfo
				} else {
					chanInfo.to = node
				}
			}

			sid, cp_paired := extractShortChanID(line)
			if sid != "" {
				chanInfo, ok := channels[cp_paired]
				if !ok {
					chanInfo = &channelInfo{
						shortChanID: sid,
					}
				} else {
					chanInfo.shortChanID = sid
				}
			}
		}
	}

	for newFilename, newLogs := range newFiles {
		// Replace all nodes with human-readable names for each of the
		// files.
		for _, n := range nodes {
			if n.pubKey == "" {
				fmt.Println("didn't find public key for: ",
					n.name)
				continue
			}
			newLogs = strings.Replace(
				newLogs, n.pubKey,
				fmt.Sprintf("[%s]", n.name), -1,
			)
		}

		for cp, info := range channels {
			channelPoint := fmt.Sprintf("[ChanPoint: %s=>%s]",
				info.from.name, info.to.name)
			newLogs = strings.Replace(newLogs, cp, channelPoint, -1)

			if info.shortChanID == "" {
				continue
			}

			shortChannelID := fmt.Sprintf("[SID: %s=>%s]",
				info.from.name, info.to.name)
			newLogs = strings.Replace(
				newLogs, info.shortChanID, shortChannelID, -1,
			)
		}

		sortedLogs := sortLinesByTimestamp(newLogs)

		err = ioutil.WriteFile(newFilename, []byte(sortedLogs), 0644)
		if err != nil {
			fmt.Println("save file got:", newFilename, err)
		}
	}

	// channelInfoByTest groups channel info by each test.
	channelInfoByTest := make(map[string]map[string]*channelInfo)
	for cp, chanInfo := range channels {
		testName := chanInfo.from.testName
		info, ok := channelInfoByTest[testName]
		if !ok {
			info = make(map[string]*channelInfo)
		}

		info[cp] = chanInfo
		channelInfoByTest[testName] = info
	}

	for name, channels := range channelInfoByTest {
		desc := "test: %s\n"
		fmt.Printf(desc, name)
		for cp, info := range channels {
			template := "%s, %s => %s, scid: %s\n"
			fmt.Printf(
				template, cp, info.from.name,
				info.to.name, info.shortChanID,
			)
		}
		fmt.Println()
	}
}

type sortedLine struct {
	ts   time.Time
	line string
}

func sortLinesByTimestamp(logFile string) string {
	lines := strings.Split(logFile, "\n")
	newLines := make([]*sortedLine, 0, len(lines))

	multiLines := ""
	for _, line := range lines {
		if multiLines == "" {
			multiLines = line
		}

		tsStr := strings.Split(line, "[")[0]
		tsStr = strings.TrimSpace(tsStr)

		ts, err := time.Parse("2006-01-02 15:04:05.000", tsStr)
		if err != nil {
			multiLines += line + "\n"
			continue
		}

		newLines = append(newLines, &sortedLine{
			ts:   ts,
			line: multiLines,
		})

		multiLines = ""
	}

	sort.Slice(newLines, func(i, j int) bool {
		return newLines[i].ts.Before(newLines[j].ts)
	})

	sortedLines := make([]string, 0, len(lines))
	for _, sl := range newLines {
		multiLines := strings.Split(sl.line, "\n")
		sortedLines = append(sortedLines, multiLines...)
	}

	return strings.Join(sortedLines, "\n")
}

For instance, it will change these lines,

2022-12-13 05:32:55.326 [DBG] PEER: Peer(0380857c82da12098fd7bed64489b096a0d4edee4ee02fc86478cf72250d4d8795): Sending GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2022-12-13 05:32:55 +0000 UTC, stamp_range=4294967295) to 0380857c82da12098fd7bed64489b096a0d4edee4ee02fc86478cf72250d4d8795@127.0.0.1:8567
2022-12-13 05:32:55.326 [DBG] PEER: Peer(0380857c82da12098fd7bed64489b096a0d4edee4ee02fc86478cf72250d4d8795): Received GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2022-12-13 05:32:55 +0000 UTC, stamp_range=4294967295) from 0380857c82da12098fd7bed64489b096a0d4edee4ee02fc86478cf72250d4d8795@127.0.0.1:8567

into these lines,

2022-12-13 05:32:55.326 [DBG] PEER: Peer([Bob]): Sending GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2022-12-13 05:32:55 +0000 UTC, stamp_range=4294967295) to [Bob]@127.0.0.1:8567
2022-12-13 05:32:55.326 [DBG] PEER: Peer([Bob]): Received GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2022-12-13 05:32:55 +0000 UTC, stamp_range=4294967295) from [Bob]@127.0.0.1:8567