443 lines
12 KiB
Go
443 lines
12 KiB
Go
//go:build linux
|
|
|
|
package transport
|
|
|
|
import (
|
|
"encoding/binary"
|
|
"net"
|
|
"reflect"
|
|
"syscall"
|
|
"testing"
|
|
|
|
"omnisocketgo/cmd/internal/latencylog"
|
|
"omnisocketgo/cmd/internal/protocol"
|
|
)
|
|
|
|
func TestLinuxTimestampingRecordsKernelEvents(t *testing.T) {
|
|
tests := []struct {
|
|
name string
|
|
msg protocol.Message
|
|
}{
|
|
{
|
|
name: "text",
|
|
msg: protocol.Message{
|
|
Type: protocol.MessageTypeText,
|
|
ID: 41,
|
|
From: "peer-a",
|
|
To: "peer-b",
|
|
Body: []byte("hello over tcp"),
|
|
},
|
|
},
|
|
{
|
|
name: "file",
|
|
msg: protocol.Message{
|
|
Type: protocol.MessageTypeFile,
|
|
ID: 42,
|
|
From: "peer-a",
|
|
To: "peer-b",
|
|
FileName: "payload.bin",
|
|
Body: []byte{0x00, 0x01, 0x02, 0xff},
|
|
},
|
|
},
|
|
}
|
|
|
|
for _, tt := range tests {
|
|
t.Run(tt.name, func(t *testing.T) {
|
|
clientConn, serverConn := newTCPPair(t)
|
|
|
|
senderLogger := &recordingLogger{}
|
|
receiverLogger := &recordingLogger{}
|
|
sender, err := NewTCPConn(
|
|
clientConn,
|
|
WithLogger(senderLogger, latencylog.NodeRolePeer, "peer-a"),
|
|
)
|
|
if err != nil {
|
|
t.Fatalf("NewTCPConn(sender) error = %v", err)
|
|
}
|
|
receiver, err := NewTCPConn(
|
|
serverConn,
|
|
WithLogger(receiverLogger, latencylog.NodeRolePeer, "peer-b"),
|
|
)
|
|
if err != nil {
|
|
t.Fatalf("NewTCPConn(receiver) error = %v", err)
|
|
}
|
|
t.Cleanup(func() {
|
|
_ = sender.Close()
|
|
_ = receiver.Close()
|
|
})
|
|
|
|
sendErr := make(chan error, 1)
|
|
go func() {
|
|
sendErr <- sender.Send(tt.msg)
|
|
}()
|
|
|
|
got, err := receiver.Receive()
|
|
if err != nil {
|
|
t.Fatalf("Receive() error = %v", err)
|
|
}
|
|
if err := <-sendErr; err != nil {
|
|
t.Fatalf("Send() error = %v", err)
|
|
}
|
|
if !reflect.DeepEqual(got, tt.msg) {
|
|
t.Fatalf("message mismatch: got %+v want %+v", got, tt.msg)
|
|
}
|
|
|
|
assertHasEvent(t, senderLogger.Events(), latencylog.EventATXSched, tt.msg.ID)
|
|
assertHasEvent(t, senderLogger.Events(), latencylog.EventATXSoftware, tt.msg.ID)
|
|
assertHasEvent(t, receiverLogger.Events(), latencylog.EventBRXSoftware, tt.msg.ID)
|
|
})
|
|
}
|
|
}
|
|
|
|
func TestParseTXTimestampSocketControlMessagesExtractsEventKindAndID(t *testing.T) {
|
|
tests := []struct {
|
|
name string
|
|
kind uint32
|
|
wantEvent string
|
|
}{
|
|
{
|
|
name: "sched",
|
|
kind: linuxSCMTstampSched,
|
|
wantEvent: latencylog.EventATXSched,
|
|
},
|
|
{
|
|
name: "software",
|
|
kind: linuxSCMTstampSnd,
|
|
wantEvent: latencylog.EventATXSoftware,
|
|
},
|
|
}
|
|
|
|
for _, tt := range tests {
|
|
t.Run(tt.name, func(t *testing.T) {
|
|
controlMessages := []syscall.SocketControlMessage{
|
|
makeTimestampSocketControlMessage(1_700_000_000_123_456_789),
|
|
makeSocketExtendedErrControlMessage(tt.kind, 42),
|
|
}
|
|
|
|
event, ok := parseTXTimestampSocketControlMessages(controlMessages)
|
|
if !ok {
|
|
t.Fatal("parseTXTimestampSocketControlMessages() ok = false, want true")
|
|
}
|
|
if event.EventName != tt.wantEvent {
|
|
t.Fatalf("event name = %q, want %q", event.EventName, tt.wantEvent)
|
|
}
|
|
if event.TSUnixNano != 1_700_000_000_123_456_789 {
|
|
t.Fatalf("timestamp = %d, want %d", event.TSUnixNano, int64(1_700_000_000_123_456_789))
|
|
}
|
|
if event.EEInfo != tt.kind {
|
|
t.Fatalf("ee_info = %d, want %d", event.EEInfo, tt.kind)
|
|
}
|
|
if event.EEData != 42 {
|
|
t.Fatalf("ee_data = %d, want 42", event.EEData)
|
|
}
|
|
})
|
|
}
|
|
}
|
|
|
|
func TestSelectTXTimestampEventsPrefersExactFinalChunkID(t *testing.T) {
|
|
events := []observedTXTimestampEvent{
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSched, TSUnixNano: 100, EEData: 7}},
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSoftware, TSUnixNano: 110, EEData: 7}},
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSched, TSUnixNano: 200, EEData: 9}},
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSoftware, TSUnixNano: 210, EEData: 9}},
|
|
}
|
|
|
|
selection := selectTXTimestampEvents(events, 9, true)
|
|
if !selection.HasEvent {
|
|
t.Fatal("selection.HasEvent = false, want true")
|
|
}
|
|
if selection.SelectedID != 9 {
|
|
t.Fatalf("SelectedID = %d, want 9", selection.SelectedID)
|
|
}
|
|
if got := selection.Timestamps[latencylog.EventATXSched]; got != 200 {
|
|
t.Fatalf("selected sched = %d, want 200", got)
|
|
}
|
|
if got := selection.Timestamps[latencylog.EventATXSoftware]; got != 210 {
|
|
t.Fatalf("selected software = %d, want 210", got)
|
|
}
|
|
}
|
|
|
|
func TestSelectTXTimestampEventsFallsBackToHighestObservedID(t *testing.T) {
|
|
events := []observedTXTimestampEvent{
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSched, TSUnixNano: 100, EEData: 11}},
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSoftware, TSUnixNano: 120, EEData: 11}},
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSched, TSUnixNano: 200, EEData: 15}},
|
|
{Event: txTimestampEvent{EventName: latencylog.EventATXSoftware, TSUnixNano: 220, EEData: 15}},
|
|
}
|
|
|
|
selection := selectTXTimestampEvents(events, 20, true)
|
|
if !selection.HasEvent {
|
|
t.Fatal("selection.HasEvent = false, want true")
|
|
}
|
|
if selection.SelectedID != 15 {
|
|
t.Fatalf("SelectedID = %d, want 15", selection.SelectedID)
|
|
}
|
|
if got := selection.Timestamps[latencylog.EventATXSched]; got != 200 {
|
|
t.Fatalf("selected sched = %d, want 200", got)
|
|
}
|
|
if got := selection.Timestamps[latencylog.EventATXSoftware]; got != 220 {
|
|
t.Fatalf("selected software = %d, want 220", got)
|
|
}
|
|
}
|
|
|
|
func TestLinuxTimestampingDebugLoggerCapturesChunkAndErrqueueEvents(t *testing.T) {
|
|
clientConn, serverConn := newTCPPair(t)
|
|
setTCPWriteBuffer(t, clientConn, 10*1024*1024)
|
|
|
|
debugLogger := &recordingTXTimestampDebugLogger{}
|
|
senderLogger := &recordingLogger{}
|
|
receiverLogger := &recordingLogger{}
|
|
sender, err := NewTCPConn(
|
|
clientConn,
|
|
WithLogger(senderLogger, latencylog.NodeRolePeer, "peer-a"),
|
|
WithTXTimestampDebugLogger(debugLogger),
|
|
)
|
|
if err != nil {
|
|
t.Fatalf("NewTCPConn(sender) error = %v", err)
|
|
}
|
|
receiver, err := NewTCPConn(
|
|
serverConn,
|
|
WithLogger(receiverLogger, latencylog.NodeRolePeer, "peer-b"),
|
|
)
|
|
if err != nil {
|
|
t.Fatalf("NewTCPConn(receiver) error = %v", err)
|
|
}
|
|
t.Cleanup(func() {
|
|
_ = sender.Close()
|
|
_ = receiver.Close()
|
|
})
|
|
|
|
body := make([]byte, 1<<20)
|
|
for i := range body {
|
|
body[i] = byte(i % 251)
|
|
}
|
|
msg := protocol.Message{
|
|
Type: protocol.MessageTypeFile,
|
|
ID: 99,
|
|
From: "peer-a",
|
|
To: "peer-b",
|
|
FileName: "payload.bin",
|
|
Body: body,
|
|
}
|
|
|
|
sendErr := make(chan error, 1)
|
|
go func() {
|
|
sendErr <- sender.Send(msg)
|
|
}()
|
|
|
|
got, err := receiver.Receive()
|
|
if err != nil {
|
|
t.Fatalf("Receive() error = %v", err)
|
|
}
|
|
if err := <-sendErr; err != nil {
|
|
t.Fatalf("Send() error = %v", err)
|
|
}
|
|
if !reflect.DeepEqual(got, msg) {
|
|
t.Fatalf("message mismatch: got %+v want %+v", got, msg)
|
|
}
|
|
|
|
assertHasEvent(t, senderLogger.Events(), latencylog.EventATXSched, msg.ID)
|
|
assertHasEvent(t, senderLogger.Events(), latencylog.EventATXSoftware, msg.ID)
|
|
assertHasEvent(t, receiverLogger.Events(), latencylog.EventBRXSoftware, msg.ID)
|
|
|
|
sendChunkRecords := debugRecordsByType(debugLogger.Records(), txTimestampDebugRecordTypeSendChunk)
|
|
errqueueRecords := debugRecordsByType(debugLogger.Records(), txTimestampDebugRecordTypeErrqueueEvent)
|
|
if len(sendChunkRecords) == 0 {
|
|
t.Fatal("send_chunk debug records = 0, want at least 1")
|
|
}
|
|
if len(errqueueRecords) == 0 {
|
|
t.Fatal("errqueue_event debug records = 0, want at least 1")
|
|
}
|
|
|
|
finalChunkRecord := sendChunkRecords[len(sendChunkRecords)-1]
|
|
if finalChunkRecord.ExpectedTXID == nil {
|
|
t.Fatal("final send_chunk expected_tx_id = nil, want non-nil")
|
|
}
|
|
finalExpectedTXID := *finalChunkRecord.ExpectedTXID
|
|
|
|
selectedRecords := selectedErrqueueRecords(errqueueRecords)
|
|
if len(selectedRecords) == 0 {
|
|
t.Fatal("selected errqueue debug records = 0, want at least 1")
|
|
}
|
|
|
|
highestObservedID := uint32(0)
|
|
haveHighestObservedID := false
|
|
haveExactFinalID := false
|
|
for _, record := range errqueueRecords {
|
|
if record.EEData == nil {
|
|
continue
|
|
}
|
|
if !haveHighestObservedID || *record.EEData > highestObservedID {
|
|
highestObservedID = *record.EEData
|
|
haveHighestObservedID = true
|
|
}
|
|
if *record.EEData == finalExpectedTXID && isBusinessTXTimestampRecord(record) {
|
|
haveExactFinalID = true
|
|
}
|
|
}
|
|
if !haveHighestObservedID {
|
|
t.Fatal("highestObservedID missing, want at least one ee_data")
|
|
}
|
|
|
|
wantSelectedID := highestObservedID
|
|
if haveExactFinalID {
|
|
wantSelectedID = finalExpectedTXID
|
|
}
|
|
for _, record := range selectedRecords {
|
|
if record.EEData == nil {
|
|
t.Fatalf("selected record missing ee_data: %+v", record)
|
|
}
|
|
if *record.EEData != wantSelectedID {
|
|
t.Fatalf("selected ee_data = %d, want %d", *record.EEData, wantSelectedID)
|
|
}
|
|
}
|
|
|
|
selectedByEventName := make(map[string]int64, len(selectedRecords))
|
|
for _, record := range selectedRecords {
|
|
if record.TSUnixNano == nil {
|
|
t.Fatalf("selected record missing timestamp: %+v", record)
|
|
}
|
|
selectedByEventName[record.EventName] = *record.TSUnixNano
|
|
}
|
|
|
|
senderEventsByName := make(map[string]int64)
|
|
for _, event := range senderLogger.Events() {
|
|
if event.MessageID != msg.ID {
|
|
continue
|
|
}
|
|
if !isBusinessTXTimestampEventName(event.Event) {
|
|
continue
|
|
}
|
|
senderEventsByName[event.Event] = event.TsUnixNano
|
|
}
|
|
|
|
for eventName, selectedTS := range selectedByEventName {
|
|
if senderEventsByName[eventName] != selectedTS {
|
|
t.Fatalf("sender latency event %s = %d, want %d from selected debug record", eventName, senderEventsByName[eventName], selectedTS)
|
|
}
|
|
}
|
|
}
|
|
|
|
func newTCPPair(t *testing.T) (net.Conn, net.Conn) {
|
|
t.Helper()
|
|
|
|
listener, err := net.Listen("tcp", "127.0.0.1:0")
|
|
if err != nil {
|
|
t.Fatalf("net.Listen() error = %v", err)
|
|
}
|
|
|
|
type acceptResult struct {
|
|
conn net.Conn
|
|
err error
|
|
}
|
|
|
|
accepted := make(chan acceptResult, 1)
|
|
go func() {
|
|
conn, acceptErr := listener.Accept()
|
|
accepted <- acceptResult{conn: conn, err: acceptErr}
|
|
}()
|
|
|
|
clientConn, err := net.Dial("tcp", listener.Addr().String())
|
|
if err != nil {
|
|
_ = listener.Close()
|
|
t.Fatalf("net.Dial() error = %v", err)
|
|
}
|
|
|
|
result := <-accepted
|
|
if err := listener.Close(); err != nil {
|
|
t.Fatalf("listener.Close() error = %v", err)
|
|
}
|
|
if result.err != nil {
|
|
_ = clientConn.Close()
|
|
t.Fatalf("listener.Accept() error = %v", result.err)
|
|
}
|
|
|
|
return clientConn, result.conn
|
|
}
|
|
|
|
func assertHasEvent(t *testing.T, events []latencylog.Event, wantEvent string, wantMessageID uint64) {
|
|
t.Helper()
|
|
|
|
for _, event := range events {
|
|
if event.Event == wantEvent && event.MessageID == wantMessageID {
|
|
if event.TsUnixNano <= 0 {
|
|
t.Fatalf("event %s timestamp must be positive: %+v", wantEvent, event)
|
|
}
|
|
return
|
|
}
|
|
}
|
|
|
|
t.Fatalf("missing event %s for message %d in %+v", wantEvent, wantMessageID, events)
|
|
}
|
|
|
|
func makeTimestampSocketControlMessage(tsUnixNano int64) syscall.SocketControlMessage {
|
|
const timespec64Size = 16
|
|
|
|
data := make([]byte, timespec64Size*3)
|
|
sec := uint64(tsUnixNano / int64(1e9))
|
|
nsec := uint64(tsUnixNano % int64(1e9))
|
|
binary.NativeEndian.PutUint64(data[:8], sec)
|
|
binary.NativeEndian.PutUint64(data[8:16], nsec)
|
|
|
|
return syscall.SocketControlMessage{
|
|
Header: syscall.Cmsghdr{
|
|
Level: syscall.SOL_SOCKET,
|
|
Type: linuxSCMTimestampingNew,
|
|
},
|
|
Data: data,
|
|
}
|
|
}
|
|
|
|
func makeSocketExtendedErrControlMessage(kind, id uint32) syscall.SocketControlMessage {
|
|
data := make([]byte, 16)
|
|
data[4] = linuxSOEEOriginTimestamping
|
|
binary.NativeEndian.PutUint32(data[8:12], kind)
|
|
binary.NativeEndian.PutUint32(data[12:16], id)
|
|
|
|
return syscall.SocketControlMessage{
|
|
Header: syscall.Cmsghdr{
|
|
Level: syscall.SOL_IP,
|
|
Type: syscall.IP_RECVERR,
|
|
},
|
|
Data: data,
|
|
}
|
|
}
|
|
|
|
func setTCPWriteBuffer(t *testing.T, conn net.Conn, size int) {
|
|
t.Helper()
|
|
|
|
tcpConn, ok := conn.(*net.TCPConn)
|
|
if !ok {
|
|
t.Fatalf("conn type %T does not support SetWriteBuffer", conn)
|
|
}
|
|
if err := tcpConn.SetWriteBuffer(size); err != nil {
|
|
t.Fatalf("SetWriteBuffer(%d) error = %v", size, err)
|
|
}
|
|
}
|
|
|
|
func debugRecordsByType(records []TXTimestampDebugRecord, recordType string) []TXTimestampDebugRecord {
|
|
filtered := make([]TXTimestampDebugRecord, 0, len(records))
|
|
for _, record := range records {
|
|
if record.RecordType != recordType {
|
|
continue
|
|
}
|
|
filtered = append(filtered, record)
|
|
}
|
|
return filtered
|
|
}
|
|
|
|
func selectedErrqueueRecords(records []TXTimestampDebugRecord) []TXTimestampDebugRecord {
|
|
selected := make([]TXTimestampDebugRecord, 0, len(records))
|
|
for _, record := range records {
|
|
if record.SelectedForLatency == nil || !*record.SelectedForLatency {
|
|
continue
|
|
}
|
|
selected = append(selected, record)
|
|
}
|
|
return selected
|
|
}
|
|
|
|
func isBusinessTXTimestampRecord(record TXTimestampDebugRecord) bool {
|
|
return record.EventName == latencylog.EventATXSched || record.EventName == latencylog.EventATXSoftware
|
|
}
|