libp2p PubSub debugging / tracing

README.md

Background

While pursuing minimal background gossip support I've encountered a need more observability into the state of the network as it evolves.

Fortunately go-libp2p-pubsub includes support for tracing. example_trace.json is the result of using a JSONTracer in a background gossip broadcast integration test.

The Problem

By default, the library encodes the PeerIDs in these traces using base64 (as seen in example_trace.json). This is inconvenient as all of our logging is using the canonical string representation which makes it difficult to make use of the trace output.

A Workaround

I saw two choices:

1. Rewrite local dependencies or fork and replace go-libp2p-pubsub to patch peerID serialization just for debugging.
2. Try to re-encode the peerIDs after the fact while inspecting the trace.

Option 2 seemed like the better investment of time. With the aid of ChatGPT, I was able to pull together recode_trace_peerids.go fairly quickly.

Example:

go run ./tools/recode_trace_peerids.go ./pubsub-trace_12D3KooWRePJkgR7WADB_501.json | jq .

{
  "type": 7,
  "peerID": "12D3KooWRePJkgR7WADBpY4akqLU9hHAdK2snqDjPJHJowQBZsmJ",
  "timestamp": 1685522927800014300,
  "sendRPC": {
    "sendTo": "12D3KooWN6kuiA2kjCNtqp3RCMRP7jaR8m7PtxcGQBu4CNCpcFUY",
    "meta": {
      "subscription": [
        {
          "subscribe": true,
          "topic": "pokt/background"
        }
      ]
    }
  }
}
{
  "type": 9,
  "peerID": "12D3KooWRePJkgR7WADBpY4akqLU9hHAdK2snqDjPJHJowQBZsmJ",
  "timestamp": 1685522927800020700,
  "join": {
    "topic": "pokt/background"
  }
}
{
  "type": 4,
  "peerID": "12D3KooWRePJkgR7WADBpY4akqLU9hHAdK2snqDjPJHJowQBZsmJ",
  "timestamp": 1685522927800032800,
  "addPeer": {
    "peerID": "12D3KooWN6kuiA2kjCNtqp3RCMRP7jaR8m7PtxcGQBu4CNCpcFUY",
    "proto": "/meshsub/1.1.0"
  }
}
// ...
{
  "type": 6,
  "peerID": "12D3KooWRePJkgR7WADBpY4akqLU9hHAdK2snqDjPJHJowQBZsmJ",
  "timestamp": 1685522927800567800,
  "recvRPC": {
    "receivedFrom": "12D3KooWQtL9bE5iHpTSREWR2NnMgtLkkGPNU5jZ98UHWEQs9zg5",
    "meta": {
      "subscription": [
        {
          "subscribe": true,
          "topic": "pokt/background"
        }
      ]
    }
  }
}
// ...

example_trace.json

{"type":9,"peerID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0=","timestamp":1685522927791917353,"join":{"topic":"pokt/background"}}
{"type":6,"peerID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0=","timestamp":1685522927797207655,"recvRPC":{"receivedFrom":"ACQIARIg3+NX3lVknm0s6Ims8V63fpSrPFdW/kbTx1ONN/J/EV4=","meta":{}}}
{"type":6,"peerID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0=","timestamp":1685522927797221311,"recvRPC":{"receivedFrom":"ACQIARIg3+NX3lVknm0s6Ims8V63fpSrPFdW/kbTx1ONN/J/EV4=","meta":{"subscription":[{"subscribe":true,"topic":"pokt/background"}]}}}
{"type":6,"peerID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0=","timestamp":1685522927800117683,"recvRPC":{"receivedFrom":"ACQIARIg6yx4NkUlohDZlKg+AtGLQoergfZnDPRRCrbJ9R4pbZE=","meta":{}}}
{"type":6,"peerID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0=","timestamp":1685522927800130227,"recvRPC":{"receivedFrom":"ACQIARIg6yx4NkUlohDZlKg+AtGLQoergfZnDPRRCrbJ9R4pbZE=","meta":{"subscription":[{"subscribe":true,"topic":"pokt/background"}]}}}
{"type":0,"peerID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0=","timestamp":1685522928304152502,"publishMessage":{"messageID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0XZC4sK81FXg==","topic":"pokt/background"}}
{"type":3,"peerID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0=","timestamp":1685522928304880147,"deliverMessage":{"messageID":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0XZC4sK81FXg==","topic":"pokt/background","receivedFrom":"ACQIARIgtn8/yMNbN7clMu47+4QAbojrxrchz2CguIBHzXoKNz0="}}

recode_trace_peerids.go

package main

import (
	"bufio"
	"encoding/base64"
	"fmt"
	"os"
	"regexp"
	"strings"

	libp2pPeer "github.com/libp2p/go-libp2p/core/peer"
	"github.com/spf13/cobra"
)

const (
	peerIDPrefix = "peerID"
)

// Define the CLI commands and flags
var rootCmd = &cobra.Command{
	Use:   "tracefile",
	Short: "Tracefile is a CLI tool to parse a JSON file and replace Peer IDs.",
	Long: `Tracefile loads the localnet private keys and a given trace JSON file.
It scans through the trace file, looking for peer IDs which correspond to localnet private keys
and substitutes the peer IDs with an alternative encoding.`,
	Args: cobra.ExactArgs(1),
	RunE: execute,
}

func main() {
	if err := rootCmd.Execute(); err != nil {
		fmt.Println(err)
		os.Exit(1)
	}
}

func execute(cmd *cobra.Command, args []string) error {
	file, err := os.Open(args[0])
	if err != nil {
		return fmt.Errorf("error reading file: %w", err)
	}
	defer file.Close()

	// Regular expression to match "peerID": "xxxx", "receivedFrom": "xxxx", or "sentTo": "xxxx"
	re := regexp.MustCompile(`"(?:peerID|receivedFrom|sentTo)":"([^"]+)"`)

	scanner := bufio.NewScanner(file)
	for scanner.Scan() {
		line := scanner.Text()
		matches := re.FindAllStringSubmatch(line, -1)
		for _, match := range matches {
			// first capture group
			base64PeerID := match[1]

			peerIDBz, err := base64.StdEncoding.DecodeString(base64PeerID)
			if err != nil {
				return fmt.Errorf("decoding base64 encoded peer ID string %q: %v", base64PeerID, err)
			}

			peerID, err := libp2pPeer.IDFromBytes(peerIDBz)
			if err != nil {
				return fmt.Errorf("parsing peer ID: %v", err)
			}

			// Substitute Peer ID
			line = strings.ReplaceAll(line, base64PeerID, peerID.String())
		}
		// Print the line
		fmt.Println(line)
	}

	if err := scanner.Err(); err != nil {
		return fmt.Errorf("scanning file: %w", err)
	}
	return nil
}

@bryanchriswhite How hard would it be to further map the peerId to a semantic host we know? E.g. fisherman1 or validator2?