add more debug info around missing TX timestamp

Summary: we need this debug info to better correlate missing TX timestamp software issues with BRCM driver issues

Reviewed By: leoleovich

Differential Revision: D53325391

fbshipit-source-id: 35fa7581b59be2bf4a4ddc455ddde36efffe0b46

ptp/simpleclient/client.go

@@ -188,6 +188,7 @@ func (c *Client) sendEventMsg(p ptp.Packet) (uint16, time.Time, error) {
 	// send packet
 	_, hwts, err := c.eventConn.WriteToWithTS(b, c.eventAddr)
 	if err != nil {
+		log.Warnf("Error sending packet with SeqID = %04x: %v", seq, err)
 		return 0, time.Time{}, err
 	}
 	c.eventSequence++

ptp/sptp/client/client.go

@@ -153,6 +153,7 @@ func (c *Client) SendEventMsg(p ptp.Packet) (uint16, time.Time, error) {
 
 	c.incrementSequence()
 	if err != nil {
+		log.Warnf("Error sending packet with SeqID = %04x: %v", seq, err)
 		return 0, time.Time{}, err
 	}
 

timestamp/timestamp_linux.go

@@ -227,6 +227,7 @@ func ReadTXtimestampBuf(connFd int, oob, toob []byte) (time.Time, int, error) {
 	// We need to empty it and completely otherwise we end up with a shifted queue read:
 	// Sync is out -> read TS from the previous Sync
 	// Because we always perform at least 2 tries we start with 0 so on success we are at 1.
+	timeStart := time.Now()
 	attempts := 0
 	for ; attempts < AttemptsTXTS; attempts++ {
 		if !txfound {
@@ -251,7 +252,8 @@ func ReadTXtimestampBuf(connFd int, oob, toob []byte) (time.Time, int, error) {
 	}
 
 	if !txfound {
-		return time.Time{}, attempts, fmt.Errorf("no TX timestamp found after %d tries", AttemptsTXTS)
+		timeout := time.Since(timeStart)
+		return time.Time{}, attempts, fmt.Errorf("no TX timestamp found after %d tries (%d ms)", AttemptsTXTS, timeout.Milliseconds())
 	}
 	timestamp, err := socketControlMessageTimestamp(oob[:boob])
 	return timestamp, attempts, err

timestamp/timestamp_linux_test.go

@@ -64,7 +64,8 @@ func Test_ReadTXtimestamp(t *testing.T) {
 	duration := time.Since(start)
 	require.Equal(t, time.Time{}, txts)
 	require.Equal(t, defaultTXTS, attempts)
-	require.Equal(t, fmt.Errorf("no TX timestamp found after %d tries", defaultTXTS), err)
+	errStr := fmt.Sprintf("no TX timestamp found after %d tries", defaultTXTS)
+	require.ErrorContains(t, err, errStr)
 	require.GreaterOrEqual(t, duration, time.Duration(AttemptsTXTS)*TimeoutTXTS)
 
 	AttemptsTXTS = 10
@@ -75,7 +76,8 @@ func Test_ReadTXtimestamp(t *testing.T) {
 	duration = time.Since(start)
 	require.Equal(t, time.Time{}, txts)
 	require.Equal(t, 10, attempts)
-	require.Equal(t, fmt.Errorf("no TX timestamp found after %d tries", 10), err)
+	errStr = fmt.Sprintf("no TX timestamp found after %d tries", 10)
+	require.ErrorContains(t, err, errStr)
 	require.GreaterOrEqual(t, duration, time.Duration(AttemptsTXTS)*TimeoutTXTS)
 
 	addr := &net.UDPAddr{IP: net.ParseIP("127.0.0.1"), Port: 12345}