Files
gronod ca723d15cf Publish sanitized protocol captures and documentation
Replace device credentials and identifiers consistently across packet
captures, documentation, and tests so the protocol evidence can be shared
publicly without exposing private device or network identities.
2026-09-25 13:49:11 +01:00

753 lines
20 KiB
Go

package main
import (
"bufio"
"bytes"
"context"
"encoding/base64"
"encoding/binary"
"encoding/json"
"errors"
"fmt"
"io"
"log/slog"
"net"
"net/http"
"os"
"regexp"
"sort"
"strings"
"sync"
"testing"
"time"
"git.i3omb.com/gronod/ha-n95-local-control/internal/config"
"git.i3omb.com/gronod/ha-n95-local-control/internal/ctl"
"git.i3omb.com/gronod/ha-n95-local-control/internal/httpx"
"git.i3omb.com/gronod/ha-n95-local-control/internal/robot"
"git.i3omb.com/gronod/ha-n95-local-control/internal/session"
"git.i3omb.com/gronod/ha-n95-local-control/internal/xmpp"
)
const pcapMagicLittleEndian uint32 = 0xa1b2c3d4
var captureFilenames = []string{
"docs/pcaps/packetcapture-ix1.12-20260923211202.pcap",
"docs/pcaps/packetcapture-ix1.12-20260923214817.pcap",
"docs/pcaps/packetcapture-ix1.12-20260923223825.pcap",
"docs/pcaps/packetcapture-ix1.12-20260923230041.pcap",
}
type tcpSegment struct {
srcPort uint16
dstPort uint16
seq uint32
ack uint32
flags uint16
payload []byte
}
func readPCAPSegments(path string) ([]tcpSegment, error) {
f, err := os.Open(path)
if err != nil {
return nil, err
}
defer f.Close()
var gh struct {
Magic uint32
VersionMajor uint16
VersionMinor uint16
ThisZone int32
SigFigs uint32
SnapLen uint32
Network uint32
}
if err := binary.Read(f, binary.LittleEndian, &gh); err != nil {
return nil, err
}
if gh.Magic != pcapMagicLittleEndian {
return nil, fmt.Errorf("unexpected magic: 0x%x", gh.Magic)
}
var segs []tcpSegment
for {
var ph struct {
TsSec uint32
TsUsec uint32
InclLen uint32
OrigLen uint32
}
err := binary.Read(f, binary.LittleEndian, &ph)
if err == io.EOF || errors.Is(err, io.ErrUnexpectedEOF) {
break
}
if err != nil {
return nil, err
}
pkt := make([]byte, ph.InclLen)
if _, err := io.ReadFull(f, pkt); err != nil {
return nil, err
}
// Ethernet header (14 bytes)
if len(pkt) < 14 {
continue
}
ethType := binary.BigEndian.Uint16(pkt[12:14])
if ethType != 0x0800 { // IPv4
continue
}
ipHdr := pkt[14:]
if len(ipHdr) < 20 {
continue
}
ihl := int(ipHdr[0]&0x0f) * 4
if len(ipHdr) < ihl {
continue
}
totLen := int(binary.BigEndian.Uint16(ipHdr[2:4]))
if totLen < ihl {
continue
}
if totLen > len(ipHdr) {
totLen = len(ipHdr)
}
if ipHdr[9] != 6 { // TCP
continue
}
tcpData := ipHdr[ihl:totLen]
if len(tcpData) < 20 {
continue
}
srcPort := binary.BigEndian.Uint16(tcpData[0:2])
dstPort := binary.BigEndian.Uint16(tcpData[2:4])
seq := binary.BigEndian.Uint32(tcpData[4:8])
ack := binary.BigEndian.Uint32(tcpData[8:12])
offsetFlags := binary.BigEndian.Uint16(tcpData[12:14])
tcpLen := int((offsetFlags>>12)&0x0f) * 4
if len(tcpData) < tcpLen {
continue
}
flags := offsetFlags & 0x1ff
payload := tcpData[tcpLen:]
segs = append(segs, tcpSegment{
srcPort: srcPort,
dstPort: dstPort,
seq: seq,
ack: ack,
flags: flags,
payload: payload,
})
}
return segs, nil
}
func reassembleClientFlows(segs []tcpSegment, dstPort uint16) map[uint16][]byte {
bySrc := make(map[uint16][]tcpSegment)
for _, s := range segs {
if s.dstPort == dstPort && len(s.payload) > 0 {
bySrc[s.srcPort] = append(bySrc[s.srcPort], s)
}
}
flows := make(map[uint16][]byte)
for sport, sl := range bySrc {
sort.Slice(sl, func(i, j int) bool {
return sl[i].seq < sl[j].seq
})
var data []byte
var nextSeq uint32
first := true
for _, s := range sl {
if first {
data = append(data, s.payload...)
nextSeq = s.seq + uint32(len(s.payload))
first = false
continue
}
if s.seq <= nextSeq {
overlap := int(nextSeq - s.seq)
if overlap < len(s.payload) {
data = append(data, s.payload[overlap:]...)
nextSeq += uint32(len(s.payload) - overlap)
}
} else {
data = append(data, s.payload...)
nextSeq = s.seq + uint32(len(s.payload))
}
}
flows[sport] = data
}
return flows
}
func TestCaptureFilesPresent(t *testing.T) {
for _, name := range captureFilenames {
p, err := findRepoFile(name)
if err != nil {
t.Fatalf("capture file %s not found: %v", name, err)
}
f, err := os.Open(p)
if err != nil {
t.Fatalf("open %s: %v", p, err)
}
defer f.Close()
var magic uint32
if err := binary.Read(f, binary.LittleEndian, &magic); err != nil {
t.Fatalf("read magic from %s: %v", p, err)
}
if magic != pcapMagicLittleEndian {
t.Fatalf("file %s magic = 0x%x, want 0x%x", p, magic, pcapMagicLittleEndian)
}
}
}
func TestCapture1LookupPair(t *testing.T) {
pcapPath, err := findRepoFile("docs/pcaps/packetcapture-ix1.12-20260923211202.pcap")
if err != nil {
t.Fatalf("pcap file not found: %v", err)
}
segs, err := readPCAPSegments(pcapPath)
if err != nil {
t.Fatalf("read pcap: %v", err)
}
flows := reassembleClientFlows(segs, 8007)
if len(flows) != 2 {
t.Fatalf("expected 2 client lookup flows to port 8007, got %d", len(flows))
}
pLookup := getFreePort(t)
testAdvIP := "192.0.2.77"
cfg := config.Config{
BindAddress: "127.0.0.1",
AdvertiseIP: net.ParseIP(testAdvIP),
PortLookup: pLookup,
PortXMPP: 5223,
PortFirmware: 8005,
}
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
go func() {
_ = httpx.ServeLookup(ctx, cfg)
}()
time.Sleep(30 * time.Millisecond)
for sport, reqBytes := range flows {
conn, err := net.Dial("tcp", fmt.Sprintf("127.0.0.1:%d", pLookup))
if err != nil {
t.Fatalf("dial lookup port %d: %v", pLookup, err)
}
_, err = conn.Write(reqBytes)
if err != nil {
conn.Close()
t.Fatalf("write lookup request: %v", err)
}
resp, err := http.ReadResponse(bufio.NewReader(conn), nil)
if err != nil {
conn.Close()
t.Fatalf("read lookup response: %v", err)
}
body, err := io.ReadAll(resp.Body)
resp.Body.Close()
conn.Close()
if err != nil {
t.Fatalf("read body: %v", err)
}
if resp.StatusCode != http.StatusOK {
t.Fatalf("sport %d: status = %d, want 200", sport, resp.StatusCode)
}
bodyStr := string(body)
if strings.Contains(bodyStr, " ") || strings.Contains(bodyStr, "\n") {
t.Fatalf("sport %d: response body is not compact JSON: %q", sport, bodyStr)
}
var parsed struct {
Result string `json:"result"`
IP string `json:"ip"`
Port int `json:"port"`
}
if err := json.Unmarshal(body, &parsed); err != nil {
t.Fatalf("sport %d: invalid JSON %q: %v", sport, bodyStr, err)
}
if parsed.Result != "ok" {
t.Errorf("sport %d: result = %q, want ok", sport, parsed.Result)
}
if parsed.IP != testAdvIP {
t.Errorf("sport %d: ip = %q, want %s", sport, parsed.IP, testAdvIP)
}
if bytes.Contains(reqBytes, []byte("EcoMsgNew")) {
if parsed.Port != 5223 {
t.Errorf("EcoMsgNew port = %d, want 5223", parsed.Port)
}
} else if bytes.Contains(reqBytes, []byte("EcoUpdate")) {
if parsed.Port != 8005 {
t.Errorf("EcoUpdate port = %d, want 8005", parsed.Port)
}
} else {
t.Fatalf("sport %d: request did not match EcoMsgNew or EcoUpdate: %s", sport, reqBytes)
}
}
}
func TestCapture1Firmware404(t *testing.T) {
pcapPath, err := findRepoFile("docs/pcaps/packetcapture-ix1.12-20260923211202.pcap")
if err != nil {
t.Fatalf("pcap file not found: %v", err)
}
segs, err := readPCAPSegments(pcapPath)
if err != nil {
t.Fatalf("read pcap: %v", err)
}
flows := reassembleClientFlows(segs, 8005)
if len(flows) != 1 {
t.Fatalf("expected 1 client firmware flow to port 8005, got %d", len(flows))
}
var reqBytes []byte
for _, b := range flows {
reqBytes = b
break
}
pFirmware := getFreePort(t)
cfg := config.Config{
BindAddress: "127.0.0.1",
PortFirmware: pFirmware,
}
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
go func() {
_ = httpx.ServeFirmware(ctx, cfg)
}()
time.Sleep(30 * time.Millisecond)
conn, err := net.Dial("tcp", fmt.Sprintf("127.0.0.1:%d", pFirmware))
if err != nil {
t.Fatalf("dial firmware port %d: %v", pFirmware, err)
}
defer conn.Close()
if _, err := conn.Write(reqBytes); err != nil {
t.Fatalf("write firmware request: %v", err)
}
resp, err := http.ReadResponse(bufio.NewReader(conn), nil)
if err != nil {
t.Fatalf("read response: %v", err)
}
defer resp.Body.Close()
if resp.StatusCode != http.StatusNotFound {
t.Fatalf("status = %d, want 404", resp.StatusCode)
}
ct := resp.Header.Get("Content-Type")
if ct != "text/plain; charset=utf-8" {
t.Errorf("content-type = %q, want text/plain; charset=utf-8", ct)
}
body, err := io.ReadAll(resp.Body)
if err != nil {
t.Fatalf("read body: %v", err)
}
if string(body) != "Not Found" {
t.Fatalf("body = %q, want Not Found", string(body))
}
if len(body) != 9 {
t.Fatalf("body len = %d, want 9", len(body))
}
}
type pcapXMPPClient struct {
t *testing.T
conn net.Conn
}
func (c *pcapXMPPClient) write(b []byte) {
if _, err := c.conn.Write(b); err != nil {
c.t.Fatalf("write: %v", err)
}
}
func (c *pcapXMPPClient) readUntil(delim string) string {
buf := make([]byte, 4096)
var accumulated string
for {
c.conn.SetReadDeadline(time.Now().Add(2 * time.Second))
n, err := c.conn.Read(buf)
if n > 0 {
accumulated += string(buf[:n])
if strings.Contains(accumulated, delim) {
return accumulated
}
}
if err != nil {
c.t.Fatalf("readUntil %q failed after reading %q: %v", delim, accumulated, err)
}
}
}
func TestCapture1Handshake(t *testing.T) {
pcapPath, err := findRepoFile("docs/pcaps/packetcapture-ix1.12-20260923211202.pcap")
if err != nil {
t.Fatalf("pcap file not found: %v", err)
}
segs, err := readPCAPSegments(pcapPath)
if err != nil {
t.Fatalf("read pcap: %v", err)
}
flows := reassembleClientFlows(segs, 5223)
flow, ok := flows[10561]
if !ok {
t.Fatalf("client flow 10561 -> 5223 not found")
}
// Extract SASL character data from auth element in the captured stream.
reAuth := regexp.MustCompile(`<auth[^>]*>([^<]+)</auth>`)
authMatch := reAuth.FindSubmatch(flow)
if authMatch == nil {
t.Fatal("auth element not found in captured stream")
}
saslChars := string(authMatch[1])
// Extract handshake stanzas from captured bytes.
streamOpen1 := []byte(`<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='155.ecorobot.net' version='1.0'>`)
authStanza := reAuth.Find(flow)
streamOpen2 := []byte(`<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' to='155.ecorobot.net' version='1.0'>`)
reBind := regexp.MustCompile(`<iq\s+type='set'\s+id='0'><bind[^>]*><resource>atom</resource></bind></iq>`)
bindStanza := reBind.Find(flow)
if bindStanza == nil {
t.Fatal("bind stanza not found in flow")
}
reSession := regexp.MustCompile(`<iq\s+type='set'\s+id='1'><session[^>]*/>\s*</iq>`)
sessionStanza := reSession.Find(flow)
if sessionStanza == nil {
t.Fatal("session stanza not found in flow")
}
rePresence := regexp.MustCompile(`<presence><status>hello world</status></presence>`)
presenceStanza := rePresence.Find(flow)
if presenceStanza == nil {
t.Fatal("presence stanza not found in flow")
}
// Capture log records to ensure SASL character data is never logged.
logBuf := &safeBuffer{}
origLogOutput := logOutput
logOutput = logBuf
defer func() { logOutput = origLogOutput }()
pXMPP := getFreePort(t)
cfg := config.Config{
BindAddress: "127.0.0.1",
PortXMPP: pXMPP,
ControllerJID: "n95bridge@ecouser.net/homeassistant",
LogLevel: slog.LevelDebug,
}
registry := session.NewRegistry()
bus := session.NewBus()
server := xmpp.NewServer(cfg, registry, bus, nil, nil)
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
go func() {
_ = server.Serve(ctx)
}()
time.Sleep(30 * time.Millisecond)
netConn, err := net.Dial("tcp", fmt.Sprintf("127.0.0.1:%d", pXMPP))
if err != nil {
t.Fatalf("dial xmpp port: %v", err)
}
defer netConn.Close()
xc := &pcapXMPPClient{t: t, conn: netConn}
// 1. Initial stream open -> server features with SASL PLAIN
xc.write(streamOpen1)
feat1 := xc.readUntil("</stream:features>")
if !strings.Contains(feat1, "urn:ietf:params:xml:ns:xmpp-sasl") {
t.Fatalf("features 1 missing SASL namespace: %s", feat1)
}
// 2. Auth from pcap -> server success
xc.write(authStanza)
succ := xc.readUntil("<success")
if !strings.Contains(succ, "<success") {
t.Fatalf("expected SASL success, got: %s", succ)
}
// 3. Second stream open -> server features with bind
xc.write(streamOpen2)
feat2 := xc.readUntil("</stream:features>")
if !strings.Contains(feat2, "urn:ietf:params:xml:ns:xmpp-bind") {
t.Fatalf("features 2 missing bind: %s", feat2)
}
// 4. Bind -> server bind result with JID shape {authcid}@{domain}/{resource}
xc.write(bindStanza)
bindRes := xc.readUntil("</iq>")
reJID := regexp.MustCompile(`<jid>([^<]+)</jid>`)
jidMatch := reJID.FindStringSubmatch(bindRes)
if len(jidMatch) < 2 {
t.Fatalf("bind result missing jid: %s", bindRes)
}
boundJID := jidMatch[1]
reExpectedJID := regexp.MustCompile(`^[A-Za-z0-9]+@[A-Za-z0-9.]+/atom$`)
if !reExpectedJID.MatchString(boundJID) {
t.Fatalf("bound JID shape mismatch: %q, want {authcid}@{domain}/{resource}", boundJID)
}
// 5. Session -> server result id="1"
xc.write(sessionStanza)
sessRes := xc.readUntil("/>")
if !strings.Contains(sessRes, `type="result"`) || !strings.Contains(sessRes, `id="1"`) {
t.Fatalf("session result mismatch: %s", sessRes)
}
// 6. Dummy presence with surrounding spaces: "> dummy </presence>"
xc.write(presenceStanza)
presRes := xc.readUntil("</presence>")
if !strings.Contains(presRes, "> dummy </presence>") {
t.Fatalf("dummy presence missing surrounding spaces, got: %s", presRes)
}
// Assert that SASL character data was NEVER logged.
logs := logBuf.String()
if strings.Contains(logs, saslChars) {
t.Fatal("SASL character data from capture was found in logs")
}
// Also check that decoded SASL password does not appear in logs.
decoded, decErr := base64.StdEncoding.DecodeString(saslChars)
if decErr == nil {
parts := bytes.Split(decoded, []byte{0})
for _, part := range parts {
if len(part) > 0 && !strings.Contains(boundJID, string(part)) {
if strings.Contains(logs, string(part)) {
t.Fatal("decoded SASL password was found in logs")
}
}
}
}
}
func TestCapture1BareBattery(t *testing.T) {
pcapPath, err := findRepoFile("docs/pcaps/packetcapture-ix1.12-20260923211202.pcap")
if err != nil {
t.Fatalf("pcap file not found: %v", err)
}
segs, err := readPCAPSegments(pcapPath)
if err != nil {
t.Fatalf("read pcap: %v", err)
}
flows := reassembleClientFlows(segs, 5223)
flow, ok := flows[10561]
if !ok {
t.Fatalf("flow 10561 not found")
}
reBare := regexp.MustCompile(`(?s)<iq\s+to='[^']+'\s+type='set'\s+id='[^']+'>\s*<query\s+xmlns='com:ctl'>\s*<battery\s+power='(\d+)'\s*/>\s*</query>\s*</iq>`)
match := reBare.Find(flow)
if match == nil {
t.Fatal("bare battery stanza not found in capture 1")
}
in, err := ctl.Parse(match)
if err != nil {
t.Fatalf("ctl.Parse failed: %v", err)
}
if in.Kind != ctl.KindBattery {
t.Fatalf("parsed kind = %v, want KindBattery", in.Kind)
}
snap := robot.NewSnapshot()
if err := robot.Apply(&snap, in, ""); err != nil {
t.Fatalf("Apply bare battery failed: %v", err)
}
if snap.Attributes.BatteryLevel == nil || *snap.Attributes.BatteryLevel != 76 {
t.Fatalf("battery_level = %v, want 76", snap.Attributes.BatteryLevel)
}
// Verify actor writes no IQ result for bare battery and updates battery_level.
var mu sync.Mutex
var sentStanzas []string
var lastSnap robot.Snapshot
sendFn := func(b []byte) error {
mu.Lock()
defer mu.Unlock()
sentStanzas = append(sentStanzas, string(b))
return nil
}
pubFn := func(_ context.Context, s robot.Snapshot) {
mu.Lock()
defer mu.Unlock()
lastSnap = s
}
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
testBotJID := "E2998877665544332211@155.ecorobot.net/atom"
actor := robot.NewActor(ctx, testBotJID, "E2998877665544332211", "controller@ecouser.net/ha", pubFn, nil, nil, nil)
actor.SessionReady(session.ReadyEvent{
Generation: 1,
JID: testBotJID,
Serial: "E2998877665544332211",
Send: sendFn,
})
actor.Stanza(session.StanzaEvent{
Generation: 1,
JID: testBotJID,
Serial: "E2998877665544332211",
Stanza: match,
})
time.Sleep(50 * time.Millisecond)
mu.Lock()
defer mu.Unlock()
if len(sentStanzas) != 0 {
t.Fatalf("bare battery produced %d outbound stanzas, want 0 (no iq result)", len(sentStanzas))
}
if lastSnap.Attributes.BatteryLevel == nil || *lastSnap.Attributes.BatteryLevel != 76 {
t.Fatalf("battery_level in actor snapshot = %v, want 76", lastSnap.Attributes.BatteryLevel)
}
}
func TestCapture2Sched2(t *testing.T) {
pcapPath, err := findRepoFile("docs/pcaps/packetcapture-ix1.12-20260923214817.pcap")
if err != nil {
t.Fatalf("pcap file not found: %v", err)
}
segs, err := readPCAPSegments(pcapPath)
if err != nil {
t.Fatalf("read pcap: %v", err)
}
flows := reassembleClientFlows(segs, 5223)
flow, ok := flows[29867]
if !ok {
t.Fatalf("flow 29867 not found")
}
reSched2 := regexp.MustCompile(`(?s)<iq\s+to='[^']+'\s+type='set'\s+id='[^']+'>\s*<query\s+xmlns='com:ctl'>\s*<ctl\s+td='Sched2'>\s*<s\s+n='[^']+'[^>]*>.*?</s>\s*</ctl>\s*</query>\s*</iq>`)
match := reSched2.Find(flow)
if match == nil {
t.Fatal("Sched2 stanza not found in capture 2")
}
in, err := ctl.Parse(match)
if err != nil {
t.Fatalf("ctl.Parse failed: %v", err)
}
if in.TD != "Sched2" {
t.Fatalf("in.TD = %q, want Sched2", in.TD)
}
robot.ParseSchedules = robot.ScheduleParserHook
snap := robot.NewSnapshot()
snap.Attributes.Schedules = []robot.Schedule{
{Name: "old_sched_1", Time: "08:00", On: false},
{Name: "old_sched_2", Time: "09:00", On: true},
}
if err := robot.Apply(&snap, in, ""); err != nil {
t.Fatalf("Apply Sched2: %v", err)
}
if len(snap.Attributes.Schedules) != 1 {
t.Fatalf("expected schedules slice replaced with 1 entry, got %d", len(snap.Attributes.Schedules))
}
s := snap.Attributes.Schedules[0]
if s.Name != "17901966021514" {
t.Errorf("schedule Name = %q, want 17901966021514", s.Name)
}
if s.Time != "19:30" {
t.Errorf("schedule Time = %q, want 19:30", s.Time)
}
if !s.On {
t.Errorf("schedule On = false, want true")
}
if s.Repeat != "0001000" {
t.Errorf("schedule Repeat = %q, want 0001000", s.Repeat)
}
if s.Flag != "p" {
t.Errorf("schedule Flag = %q, want p", s.Flag)
}
if s.Action.Type != "auto" {
t.Errorf("schedule Action.Type = %q, want auto", s.Action.Type)
}
}
// TestCapture4ReconnectIsNotASleep tests the reconnect sequence documented in
// PCAP-ANALYSIS.md §11.1 and N95-FULL-SPECIFICATION.md §7:
//
// Timeline from packetcapture-ix1.12-20260923230041.pcap:
// - The last healthy bot ping was answered.
// - 120 seconds later the next bot ping was black-holed. The same TCP segment was
// retransmitted at +0.668, +2.342, +5.368, +11.426, +23.468, +47.666, and +95.863 seconds.
// - An earlier incomplete series in packetcapture-ix1.12-20260923223825.pcap used
// +0.918, +2.999, +7.016, +15.043, +31.116, and +63.289 seconds.
// - The robot sent FIN at +120.002 seconds from the original ping, with no XMPP stream
// close and without waiting for FIN-ACK.
// - A new TCP connection opened 4.999 seconds after that FIN. SYN to dummy presence took
// 0.455 seconds. There was no DNS, lookup, firmware check, or XEP-0198 resume.
//
// The bridge's deadline is 12 seconds (xmpp.PingResultTimeout). Reconnect handling
// accepts the down-then-ready transition without sleeping or delay.
func TestCapture4ReconnectIsNotASleep(t *testing.T) {
if xmpp.PingResultTimeout != 12*time.Second {
t.Fatalf("xmpp.PingResultTimeout = %v, want 12s", xmpp.PingResultTimeout)
}
start := time.Now()
registry := session.NewRegistry()
bus := session.NewBus()
testJID := "E2998877665544332211@155.ecorobot.net/atom"
serial := "E2998877665544332211"
// Register initial generation.
gen1, replaced := registry.Bind(testJID, nil, nil)
if gen1 != 1 || replaced {
t.Fatalf("initial bind: gen=%d replaced=%v", gen1, replaced)
}
// Trigger SessionDown (simulating TCP close / dead path detection).
bus.SessionDown(session.DownEvent{
Serial: serial,
JID: testJID,
Generation: 1,
Reason: "tcp-fin",
})
// Robot connects fresh socket immediately and completes re-bind to READY.
gen2, replaced := registry.Bind(testJID, nil, nil)
if gen2 != 2 || !replaced {
t.Fatalf("reconnect bind: gen=%d replaced=%v", gen2, replaced)
}
bus.SessionReady(session.ReadyEvent{
Serial: serial,
JID: testJID,
Generation: 2,
})
elapsed := time.Since(start)
if elapsed > 500*time.Millisecond {
t.Fatalf("reconnect took %v, expected in well under a second (not a sleep)", elapsed)
}
}