From: Mike Brady <4265913+mikebrady@users.noreply.github.com>
Date: Sat, 24 Apr 2021 08:23:52 +0000 (+0100)
Subject: Generate a reasonably understandable status message whenever mastership is recalculated.
X-Git-Tag: 1.1-dev~23
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=cf619ac0152bdf6c7c2b7fa5aa3cdd00efb5284a;p=thirdparty%2Fnqptp.git

Generate a reasonably understandable status message whenever mastership is recalculated.
---

diff --git a/nqptp-clock-sources.c b/nqptp-clock-sources.c
index 6aa3661..c38a9cd 100644
--- a/nqptp-clock-sources.c
+++ b/nqptp-clock-sources.c
@@ -72,8 +72,7 @@ int create_clock_source_record(char *sender_string,
     clocks_private_info[i].t2 = 0;
     clocks_private_info[i].current_stage = waiting_for_sync;
     clocks_private_info[i].vacant_samples = MAX_TIMING_SAMPLES;
-    debug(2, "activated source %d with clock_id %" PRIx64 " on ip: %s.", i,
-          clocks_private_info[i].clock_id, &clocks_private_info[i].ip);
+    debug(2, "create record for ip: %s.", &clocks_private_info[i].ip);
   } else {
     die("Clock tables full!");
   }
@@ -83,6 +82,7 @@ int create_clock_source_record(char *sender_string,
 void manage_clock_sources(uint64_t reception_time, clock_source_private_data *clocks_private_info) {
   debug(3, "manage_clock_sources");
   int i;
+
   // do a garbage collect for clock records no longer in use
   for (i = 0; i < MAX_CLOCKS; i++) {
     // only if its in use and not a timing peer... don't need a mutex to check
@@ -98,12 +98,12 @@ void manage_clock_sources(uint64_t reception_time, clock_source_private_data *cl
       // seconds to nanoseconds
       syncTimeout = syncTimeout * 1000000000;
       if (time_since_last_use > syncTimeout) {
-        debug(2, "deactivated source %d with clock_id %" PRIx64 " on ip: %s.", i,
-              clocks_private_info[i].clock_id, &clocks_private_info[i].ip);
+        debug(2, "delete record for: %s.", &clocks_private_info[i].ip);
         memset(&clocks_private_info[i], 0, sizeof(clock_source_private_data));
       }
     }
   }
+
 }
 
 // check all the entries in the clock array and mark all those that
diff --git a/nqptp-message-handlers.c b/nqptp-message-handlers.c
index 808d028..104b89e 100644
--- a/nqptp-message-handlers.c
+++ b/nqptp-message-handlers.c
@@ -19,6 +19,7 @@
 #include <errno.h>
 #include <string.h>
 #include <unistd.h>
+ #include <arpa/inet.h>
 
 #include "debug.h"
 #include "general-utilities.h"
@@ -90,10 +91,35 @@ void update_master_old(clock_source_private_data *clock_private_info) {
       debug(1, "No master clock not found!");
   }
 
-  // check
-  for (i = 0; i < MAX_CLOCKS; i++) {
-    if ((clock_private_info[i].flags & (1 << clock_is_master)) != 0)
-      debug(2, "leaving with %d as master", i);
+  int records_in_use = 0;
+  for (i = 0; i < MAX_CLOCKS; i++)
+   if (clock_private_info[i].in_use != 0)
+     records_in_use++;
+  if (records_in_use > 0) {
+    debug(1,"");
+    debug(1,"Current NQPTP Status:");
+    uint32_t peer_mask = (1 << clock_is_a_timing_peer);
+    uint32_t peer_clock_mask =  peer_mask | (1 << clock_is_valid);
+    uint32_t peer_master_mask = peer_clock_mask | (1 << clock_is_master);
+    uint32_t non_peer_clock_mask =  (1 << clock_is_valid);
+    uint32_t non_peer_master_mask = non_peer_clock_mask | (1 << clock_is_master);
+    for (i = 0; i < MAX_CLOCKS; i++) {
+      if (clock_private_info[i].in_use != 0) {
+        if ((clock_private_info[i].flags & peer_master_mask) == peer_master_mask) {
+          debug(1,"  Peer Master:     %" PRIx64 "  %s.", clock_private_info[i].clock_id, clock_private_info[i].ip);
+        } else if ((clock_private_info[i].flags & peer_clock_mask) == peer_clock_mask) {
+          debug(1,"  Peer Clock:      %" PRIx64 "  %s.", clock_private_info[i].clock_id, clock_private_info[i].ip);
+        } else if ((clock_private_info[i].flags & peer_mask) == peer_mask) {
+          debug(1,"  Peer:                              %s.",clock_private_info[i].ip);
+        } else if ((clock_private_info[i].flags & non_peer_master_mask) == non_peer_master_mask) {
+          debug(1,"  Non Peer Master: %" PRIx64 "  %s.", clock_private_info[i].clock_id, clock_private_info[i].ip);
+        } else if ((clock_private_info[i].flags & non_peer_clock_mask) == non_peer_clock_mask) {
+          debug(1,"  Non Peer Clock:  %" PRIx64 "  %s.", clock_private_info[i].clock_id, clock_private_info[i].ip);
+        } else {
+          debug(1,"  Non Peer Record:                   %s.",clock_private_info[i].ip);
+        }
+      }
+    }
   }
 }
 
@@ -103,7 +129,7 @@ void handle_control_port_messages(char *buf, ssize_t recv_len,
                                   clock_source_private_data *clock_private_info) {
   if (recv_len != -1) {
     buf[recv_len - 1] = 0; // make sure there's a null in it!
-    debug(2, "Received a new timing peer list message: \"%s\".", buf);
+    debug(1, "New timing peer list: \"%s\".", buf);
     if (buf[0] == 'T') {
 
       char *ip_list = buf + 1;
@@ -291,11 +317,13 @@ void handle_announce(char *buf, ssize_t recv_len, clock_source_private_data *clo
 
 void handle_sync(char *buf, __attribute__((unused)) ssize_t recv_len,
                  clock_source_private_data *clock_private_info, uint64_t reception_time,
-                 SOCKADDR *from_sock_addr, int socket_number) {
+                 SOCKADDR *to_sock_addr, int socket_number) {
   struct ptp_sync_message *msg = (struct ptp_sync_message *)buf;
   // this is just to see if anything interesting comes in the SYNC package
   // a non-zero origin timestamp
   // or correction field would be interesting....
+  // debug(1,"Sync from %s", clock_private_info->ip);
+
   int ck;
   int non_empty_origin_timestamp = 0;
   for (ck = 0; ck < 10; ck++) {
@@ -308,6 +336,7 @@ void handle_sync(char *buf, __attribute__((unused)) ssize_t recv_len,
   if (msg->header.correctionField != 0)
     debug(3, "correctionField: %" PRIx64 ".", msg->header.correctionField);
 
+
   int discard_sync = 0;
 
   // check if we should discard this SYNC
@@ -362,22 +391,49 @@ void handle_sync(char *buf, __attribute__((unused)) ssize_t recv_len,
       m.header.transportSpecificAndMessageID = 0x11; // Table 19, pp 125, 1 byte field
       m.header.reservedAndVersionPTP = 0x02;         // 1 byte field
       m.header.messageLength = htons(44);
-      m.header.flags = htons(0x608);
+      m.header.flags = htons(0x0400);
       m.header.sourcePortID = htons(1);
-      m.header.controlOtherMessage = 5; // 1 byte field
+      m.header.controlOtherMessage = 1; // 1 byte field
       m.header.sequenceId = htons(clock_private_info->sequence_number);
+      m.header.logMessagePeriod = 127;
       uint64_t sid = get_self_clock_id();
       memcpy(&m.header.clockIdentity, &sid, sizeof(uint64_t));
       struct msghdr header;
       struct iovec io;
       memset(&header, 0, sizeof(header));
       memset(&io, 0, sizeof(io));
-      header.msg_name = from_sock_addr;
+      header.msg_name = to_sock_addr;
       header.msg_namelen = sizeof(SOCKADDR);
       header.msg_iov = &io;
       header.msg_iov->iov_base = &m;
       header.msg_iov->iov_len = sizeof(m);
       header.msg_iovlen = 1;
+
+/*
+      void *destination_addr = NULL;
+      uint16_t destination_port = 0;
+
+      sa_family_t connection_ip_family = to_sock_addr->SAFAMILY;
+
+#ifdef AF_INET6
+      if (connection_ip_family == AF_INET6) {
+        struct sockaddr_in6 *sa6 = (struct sockaddr_in6 *)to_sock_addr;
+        destination_addr = &(sa6->sin6_addr);
+        destination_port = ntohs(sa6->sin6_port);
+      }
+#endif
+      if (connection_ip_family == AF_INET) {
+        struct sockaddr_in *sa4 = (struct sockaddr_in *)to_sock_addr;
+        destination_addr = &(sa4->sin_addr);
+        destination_port = ntohs(sa4->sin_port);
+      }
+
+
+      char destination_string[256];
+      memset(destination_string, 0, sizeof(destination_string));
+      inet_ntop(connection_ip_family, destination_addr, destination_string, sizeof(destination_string));
+       debug(1,"Send Delay_Req to %s:%u",  &destination_string, destination_port);
+*/
       clock_private_info->t3 = get_time_now(); // in case nothing better works
       if ((sendmsg(socket_number, &header, 0)) == -1) {
         // debug(1, "Error in sendmsg [errno = %d] to socket %d.", errno, socket_number);
@@ -432,6 +488,7 @@ void handle_follow_up(char *buf, __attribute__((unused)) ssize_t recv_len,
 void handle_delay_resp(char *buf, __attribute__((unused)) ssize_t recv_len,
                        clock_source_private_data *clock_private_info,
                        __attribute__((unused)) uint64_t reception_time) {
+    // debug(1,"Delay_Resp from %s", clock_private_info->ip);
   struct ptp_delay_resp_message *msg = (struct ptp_delay_resp_message *)buf;
 
   if ((clock_private_info->current_stage == follow_up_seen) &&
@@ -482,7 +539,7 @@ void handle_delay_resp(char *buf, __attribute__((unused)) ssize_t recv_len,
       if (clock_private_info->vacant_samples > 0)
         clock_private_info->vacant_samples--;
 
-      // do the mickey mouse averaging
+      // do mickey mouse averaging
       if (clock_private_info->mm_count == 0) {
         clock_private_info->mm_average = offset;
         clock_private_info->mm_count = 1;
@@ -520,6 +577,9 @@ void handle_delay_resp(char *buf, __attribute__((unused)) ssize_t recv_len,
 
       clock_private_info->previous_estimated_offset = estimated_offset;
 
+      if ((clock_private_info->flags & (1 << clock_is_valid)) == 0) {
+        debug(1,"clock %" PRIx64 " is now valid at: %s", packet_clock_id, clock_private_info->ip);
+      }
       clock_private_info->clock_id = packet_clock_id;
       clock_private_info->flags |= (1 << clock_is_valid);
       clock_private_info->local_time = clock_private_info->t2;
@@ -551,4 +611,4 @@ void handle_delay_resp(char *buf, __attribute__((unused)) ssize_t recv_len,
           ntohs(msg->header.sequenceId), follow_up_seen, clock_private_info->current_stage,
           clock_private_info->sequence_number, clock_private_info->ip);
   }
-}
\ No newline at end of file
+}