[CENNSO-1293] ipfix: use milliseconds ie for flow start/end (#356)

Use milliseconds ie instead of nanoseconds ie for flow start/end as
required by design document.

Also remove nsec related code since it incorrectly encodes values with
fraction reslution 1/(1e9) instead of 1/(2^32) as required by RFC 7011.

test/e2e/ipfix_e2e.go

@@ -526,8 +526,8 @@ func (v *ipfixVerifier) verifyIPFIXDefaultRecords() {
 		// The record looks like:
 		// mobileIMSI: 313460000000001
 		// packetTotalCount: 80
-		// flowStartNanoseconds: 2022-02-22 02:30:32.097219204 +0000 UTC
-		// flowEndNanoseconds: 2022-02-22 02:30:47.152832735 +0000 UTC
+		// flowStartMilliseconds: 2022-02-22 02:30:32.097 +0000 UTC
+		// flowEndMilliseconds: 2022-02-22 02:30:47.152 +0000 UTC
 		// sourceIPv4Address: 10.1.0.3
 		// destinationIPv4Address: 10.0.1.3
 		// protocolIdentifier: 6
@@ -536,11 +536,11 @@ func (v *ipfixVerifier) verifyIPFIXDefaultRecords() {
 		// destinationTransportPort: 80
 		gomega.Expect(r).To(gomega.HaveKeyWithValue("mobileIMSI", "313460000000001"))
 		// gomega.Expect(r).To(gomega.HaveKey("packetTotalCount"))
-		gomega.Expect(r).To(gomega.HaveKey("flowStartNanoseconds"))
-		gomega.Expect(r).To(gomega.HaveKey("flowEndNanoseconds"))
-		gomega.Expect(r["flowEndNanoseconds"]).
-			To(gomega.BeTemporally(">=", r["flowStartNanoseconds"].(time.Time)),
-				"flowEndNanoseconds >= flowStartNanoseconds")
+		gomega.Expect(r).To(gomega.HaveKey("flowStartMilliseconds"))
+		gomega.Expect(r).To(gomega.HaveKey("flowEndMilliseconds"))
+		gomega.Expect(r["flowEndMilliseconds"]).
+			To(gomega.BeTemporally(">=", r["flowStartMilliseconds"].(time.Time)),
+				"flowEndMilliseconds >= flowStartMilliseconds")
 		gomega.Expect(r).To(gomega.HaveKeyWithValue("protocolIdentifier", uint8(v.cfg.protocol)))
 
 		srcAddressKey := "sourceIPv4Address"
@@ -572,14 +572,14 @@ func (v *ipfixVerifier) verifyIPFIXDefaultRecords() {
 		if r[srcAddressKey].(net.IP).Equal(v.f.UEIP()) {
 			// upload
 			if v.ulStartTS.IsZero() {
-				v.ulStartTS = r["flowStartNanoseconds"].(time.Time)
+				v.ulStartTS = r["flowStartMilliseconds"].(time.Time)
 				// FIXME: should be working (wrong time on the VPP side?)
 				// gomega.Expect(ulStartTS).To(gomega.BeTemporally(">=", beginTS))
 			} else {
-				gomega.Expect(r["flowStartNanoseconds"]).To(gomega.Equal(v.ulStartTS))
+				gomega.Expect(r["flowStartMilliseconds"]).To(gomega.Equal(v.ulStartTS))
 			}
-			gomega.Expect(r["flowEndNanoseconds"]).To(gomega.BeTemporally(">", v.ulEndTS))
-			v.ulEndTS = r["flowEndNanoseconds"].(time.Time)
+			gomega.Expect(r["flowEndMilliseconds"]).To(gomega.BeTemporally(">", v.ulEndTS))
+			v.ulEndTS = r["flowEndMilliseconds"].(time.Time)
 			gomega.Expect(r[dstAddressKey].(net.IP).Equal(v.f.ServerIP())).To(gomega.BeTrue())
 			// gomega.Expect(r["packetTotalCount"]).To(gomega.BeNumerically(">=", ulPacketCount))
 			ulPacketCount += r["packetDeltaCount"].(uint64)
@@ -603,14 +603,14 @@ func (v *ipfixVerifier) verifyIPFIXDefaultRecords() {
 		} else {
 			// download
 			if v.dlStartTS.IsZero() {
-				v.dlStartTS = r["flowStartNanoseconds"].(time.Time)
+				v.dlStartTS = r["flowStartMilliseconds"].(time.Time)
 				// FIXME: should be working (wrong time on the VPP side?)
 				// gomega.Expect(dlStartTS).To(gomega.BeTemporally(">=", beginTS))
 			} else {
-				gomega.Expect(r["flowStartNanoseconds"]).To(gomega.Equal(v.dlStartTS))
+				gomega.Expect(r["flowStartMilliseconds"]).To(gomega.Equal(v.dlStartTS))
 			}
-			gomega.Expect(r["flowEndNanoseconds"]).To(gomega.BeTemporally(">=", v.dlEndTS))
-			v.dlEndTS = r["flowEndNanoseconds"].(time.Time)
+			gomega.Expect(r["flowEndMilliseconds"]).To(gomega.BeTemporally(">=", v.dlEndTS))
+			v.dlEndTS = r["flowEndMilliseconds"].(time.Time)
 			gomega.Expect(r[srcAddressKey].(net.IP).Equal(v.f.ServerIP())).To(gomega.BeTrue())
 			gomega.Expect(r[dstAddressKey].(net.IP).Equal(v.f.UEIP())).To(gomega.BeTrue())
 			// gomega.Expect(r["packetTotalCount"]).To(gomega.BeNumerically(">=", dlPacketCount))
@@ -645,7 +645,7 @@ func (v *ipfixVerifier) verifyIPFIXDestRecords() {
 	var ulOctets, dlOctets uint64
 	// var initiatorOctets, responderOctets uint64
 	for _, r := range v.recs {
-		gomega.Expect(r).To(gomega.HaveKey("flowEndNanoseconds"))
+		gomega.Expect(r).To(gomega.HaveKey("flowEndMilliseconds"))
 
 		srcAddressKey := "sourceIPv4Address"
 		dstAddressKey := "destinationIPv4Address"
@@ -687,8 +687,8 @@ func (v *ipfixVerifier) verifyIPFIXDestRecords() {
 
 		if r[srcAddressKey].(net.IP).Equal(v.f.UEIP()) {
 			// upload
-			gomega.Expect(r["flowEndNanoseconds"]).To(gomega.BeTemporally(">", v.ulEndTS))
-			v.ulEndTS = r["flowEndNanoseconds"].(time.Time)
+			gomega.Expect(r["flowEndMilliseconds"]).To(gomega.BeTemporally(">", v.ulEndTS))
+			v.ulEndTS = r["flowEndMilliseconds"].(time.Time)
 			expectedEgressVRFID := uint32(200)
 			serverIP := v.f.ServerIP()
 			if v.altServerIP != nil {
@@ -707,8 +707,8 @@ func (v *ipfixVerifier) verifyIPFIXDestRecords() {
 			ulOctets += r["octetDeltaCount"].(uint64)
 		} else {
 			// download
-			gomega.Expect(r["flowEndNanoseconds"]).To(gomega.BeTemporally(">=", v.dlEndTS))
-			v.dlEndTS = r["flowEndNanoseconds"].(time.Time)
+			gomega.Expect(r["flowEndMilliseconds"]).To(gomega.BeTemporally(">=", v.dlEndTS))
+			v.dlEndTS = r["flowEndMilliseconds"].(time.Time)
 			serverIP := v.f.ServerIP()
 			if v.altServerIP != nil {
 				serverIP = v.altServerIP.IP

upf/flowtable.c

@@ -362,7 +362,7 @@ u32
 flowtable_entry_lookup_create (flowtable_main_t * fm,
 			       flowtable_main_per_cpu_t * fmt,
 			       clib_bihash_kv_48_8_t * kv,
-			       timestamp_nsec_t timestamp, u32 const now,
+			       u64 timestamp_ns, u32 const now,
 			       u8 is_reverse, u16 generation,
 			       u32 next_session_flow_index, int *created)
 {
@@ -399,8 +399,8 @@ flowtable_entry_lookup_create (flowtable_main_t * fm,
   f->is_reverse = is_reverse;
   f->lifetime = flowtable_lifetime_calculate (fm, &f->key);
   f->active = now;
-  f->flow_start = timestamp;
-  f->flow_end = timestamp;
+  f->flow_start_time = timestamp_ns;
+  f->flow_end_time = timestamp_ns;
   f->application_id = ~0;
   flow_ipfix_info (f, FT_ORIGIN) = ~0;
   flow_ipfix_info (f, FT_REVERSE) = ~0;

upf/flowtable.h

@@ -112,12 +112,6 @@ typedef struct flow_tc
   u32 thread_index;
 } flow_tc_t;
 
-typedef struct
-{
-  u32 sec;
-  u32 nsec;
-} timestamp_nsec_t;
-
 typedef struct flow_entry
 {
   /* Required for pool_get_aligned  */
@@ -158,8 +152,8 @@ typedef struct flow_entry
 
   u8 *app_uri;
 
-  timestamp_nsec_t flow_start;
-  timestamp_nsec_t flow_end;
+  u64 flow_start_time;		/* unix nanoseconds */
+  u64 flow_end_time;		/* unix nanoseconds */
 
   u32 last_exported[FT_ORDER_MAX];
   u32 ipfix_info_index[FT_ORDER_MAX];
@@ -327,7 +321,7 @@ u32
 flowtable_entry_lookup_create (flowtable_main_t * fm,
 			       flowtable_main_per_cpu_t * fmt,
 			       clib_bihash_kv_48_8_t * kv,
-			       timestamp_nsec_t timestamp, u32 const now,
+			       u64 timestamp_ns, u32 const now,
 			       u8 is_reverse, u16 generation,
 			       u32 next_session_flow_index, int *created);
 
@@ -475,8 +469,7 @@ flow_update (vlib_main_t * vm, flow_entry_t * f,
 
 always_inline void
 flow_update_stats (vlib_main_t * vm, vlib_buffer_t * b,
-		   flow_entry_t * f, u8 is_ip4,
-		   timestamp_nsec_t timestamp, u32 now)
+		   flow_entry_t * f, u8 is_ip4, u64 timestamp_ns, u32 now)
 {
   flowtable_main_t *fm = &flowtable_main;
   /*
@@ -513,7 +506,7 @@ flow_update_stats (vlib_main_t * vm, vlib_buffer_t * b,
   f->stats[is_reverse].bytes_unreported += len;
   f->stats[is_reverse].l4_bytes += l4_len;
   f->stats[is_reverse].l4_bytes_unreported += l4_len;
-  f->flow_end = timestamp;
+  f->flow_end_time = timestamp_ns;
 
   flowtable_handle_event (fm, f, FLOW_EVENT_STATS_UPDATE, direction, now);
 }

upf/upf_flow_node.c

@@ -110,7 +110,7 @@ upf_flow_process (vlib_main_t * vm, vlib_node_runtime_t * node,
   flowtable_main_t *fm = &flowtable_main;
   u32 cpu_index = os_get_thread_index ();
   flowtable_main_per_cpu_t *fmt = &fm->per_cpu[cpu_index];
-  timestamp_nsec_t timestamp;
+  u64 timestamp_ns;
 
 #define _(sym, str) u32 CPT_ ## sym = 0;
   foreach_flowtable_error
@@ -121,7 +121,7 @@ upf_flow_process (vlib_main_t * vm, vlib_node_runtime_t * node,
 
   u32 current_time = (u32) vlib_time_now (vm);
   timer_wheel_index_update (fm, fmt, current_time);
-  unix_time_now_nsec_fraction (&timestamp.sec, &timestamp.nsec);
+  timestamp_ns = unix_time_now_nsec ();
 
   while (n_left_from > 0)
     {
@@ -224,7 +224,7 @@ upf_flow_process (vlib_main_t * vm, vlib_node_runtime_t * node,
 	  /* lookup/create flow */
 	  flow_idx0 =
 	    flowtable_entry_lookup_create (fm, fmt, &kv0,
-					   timestamp, current_time,
+					   timestamp_ns, current_time,
 					   is_reverse0, sx0->generation,
 					   sx0->first_flow_index, &created0);
 	  if (created0)
@@ -238,7 +238,7 @@ upf_flow_process (vlib_main_t * vm, vlib_node_runtime_t * node,
 
 	  flow_idx1 =
 	    flowtable_entry_lookup_create (fm, fmt, &kv1,
-					   timestamp, current_time,
+					   timestamp_ns, current_time,
 					   is_reverse1, sx1->generation,
 					   sx1->first_flow_index, &created1);
 	  if (created1)
@@ -379,7 +379,7 @@ upf_flow_process (vlib_main_t * vm, vlib_node_runtime_t * node,
 	  flow_mk_key (sx0->cp_seid, p, is_ip4, &is_reverse, &kv);
 	  flow_idx =
 	    flowtable_entry_lookup_create (fm, fmt, &kv,
-					   timestamp, current_time,
+					   timestamp_ns, current_time,
 					   is_reverse, sx0->generation,
 					   sx0->first_flow_index, &created);
 	  if (created)

upf/upf_forward.c

@@ -101,7 +101,7 @@ upf_forward (vlib_main_t * vm, vlib_node_runtime_t * node,
   upf_main_t *gtm = &upf_main;
   vnet_main_t *vnm = gtm->vnet_main;
   vnet_interface_main_t *im = &vnm->interface_main;
-  timestamp_nsec_t timestamp;
+  u64 timestamp_ns;
   u32 current_time = (u32) vlib_time_now (vm);
   flowtable_main_t *fm = &flowtable_main;
 
@@ -122,7 +122,7 @@ upf_forward (vlib_main_t * vm, vlib_node_runtime_t * node,
   next_index = node->cached_next_index;
   stats_sw_if_index = node->runtime_data[0];
   stats_n_packets = stats_n_bytes = 0;
-  unix_time_now_nsec_fraction (&timestamp.sec, &timestamp.nsec);
+  timestamp_ns = unix_time_now_nsec ();
 
   while (n_left_from > 0)
     {
@@ -322,7 +322,7 @@ upf_forward (vlib_main_t * vm, vlib_node_runtime_t * node,
 		    pool_elt_at_index (fm->flows,
 				       upf_buffer_opaque (b)->gtpu.flow_id);
 		  flow_update_stats (vm, b, flow, is_ip4,
-				     timestamp, current_time);
+				     timestamp_ns, current_time);
 		}
 	    }
 

upf/upf_ipfix_templates.c

@@ -48,8 +48,8 @@
   IPFIX_FIELD_MOBILE_IMSI(F)			\
   IPFIX_FIELD_PACKET_DELTA_COUNT(F)		\
   IPFIX_FIELD_OCTET_DELTA_COUNT(F)		\
-  IPFIX_FIELD_FLOW_START_NANOSECONDS(F)		\
-  IPFIX_FIELD_FLOW_END_NANOSECONDS(F)		\
+  IPFIX_FIELD_FLOW_START_MILLISECONDS(F)	\
+  IPFIX_FIELD_FLOW_END_MILLISECONDS(F)		\
   IPFIX_FIELD_SOURCE_TRANSPORT_PORT(F)		\
   IPFIX_FIELD_DESTINATION_TRANSPORT_PORT(F)
 
@@ -103,7 +103,7 @@ upf_ipfix_template_default_ip6_values (vlib_buffer_t * to_b,
 
 #define IPFIX_TEMPLATE_DEST_COMMON(F)	       	\
   IPFIX_FIELD_OCTET_DELTA_COUNT(F)		\
-  IPFIX_FIELD_FLOW_END_NANOSECONDS(F)		\
+  IPFIX_FIELD_FLOW_END_MILLISECONDS(F)		\
   IPFIX_FIELD_FLOW_DIRECTION(F)			\
   IPFIX_FIELD_INGRESS_VRF_ID(F)			\
   IPFIX_FIELD_EGRESS_VRF_ID(F)			\

upf/upf_ipfix_templates.h

@@ -86,14 +86,11 @@
     v = 0;							\
   } while (0)
 
-#define IPFIX_VALUE_NSEC(v, n, c)				\
+#define IPFIX_VALUE_DATETIME_MILLISECONDS(v, n, c)		\
   do {								\
-    u32 tmp = clib_host_to_net_u32((v).sec + NTP_TIMESTAMP);	\
-    clib_memcpy_fast (to_b->data + offset, &tmp, sizeof (u32));	\
-    offset += sizeof (u32);					\
-    tmp = clib_host_to_net_u32((v).nsec);			\
-    clib_memcpy_fast (to_b->data + offset, &tmp, sizeof (u32));	\
-    offset += sizeof (u32);					\
+    u64 tmp = clib_host_to_net_u64((v) / (1000 * 1000));	\
+    clib_memcpy_fast (to_b->data + offset, &tmp, sizeof (u64));	\
+    offset += sizeof (u64);					\
   } while (0)
 
 #define IPFIX_VALUE_MOBILE_IMSI(v, n, c)		\
@@ -180,16 +177,16 @@
     IPFIX_VALUE_U64,						\
     flow_stats(f, direction).bytes,				\
     sizeof (u64), 1)
-#define IPFIX_FIELD_FLOW_START_NANOSECONDS(F)			\
-  F(flowStartNanoseconds, 8,					\
-    IPFIX_VALUE_NSEC,						\
-    f->flow_start,						\
-    sizeof(u32), 1)
-#define IPFIX_FIELD_FLOW_END_NANOSECONDS(F)			\
-  F(flowEndNanoseconds, 8,					\
-    IPFIX_VALUE_NSEC,						\
-    f->flow_end,						\
-    sizeof(u32), 1)
+#define IPFIX_FIELD_FLOW_START_MILLISECONDS(F)			\
+  F(flowStartMilliseconds, 8,					\
+    IPFIX_VALUE_DATETIME_MILLISECONDS,				\
+    f->flow_start_time,						\
+    sizeof(u64), 1)
+#define IPFIX_FIELD_FLOW_END_MILLISECONDS(F)			\
+  F(flowEndMilliseconds, 8,					\
+    IPFIX_VALUE_DATETIME_MILLISECONDS,				\
+    f->flow_end_time,						\
+    sizeof(u64), 1)
 #define IPFIX_FIELD_FLOW_DIRECTION(F)				\
   F(flowDirection, 1,						\
     IPFIX_VALUE_DIRECT,						\

upf/upf_proxy_input.c

@@ -296,7 +296,7 @@ upf_proxy_input (vlib_main_t * vm, vlib_node_runtime_t * node,
   vnet_main_t *vnm = gtm->vnet_main;
   vnet_interface_main_t *im = &vnm->interface_main;
   flowtable_main_t *fm = &flowtable_main;
-  timestamp_nsec_t timestamp;
+  u64 timestamp_ns;
   u32 current_time = (u32) vlib_time_now (vm);
 
   from = vlib_frame_vector_args (from_frame);
@@ -311,7 +311,7 @@ upf_proxy_input (vlib_main_t * vm, vlib_node_runtime_t * node,
   next_index = node->cached_next_index;
   stats_sw_if_index = node->runtime_data[0];
   stats_n_packets = stats_n_bytes = 0;
-  unix_time_now_nsec_fraction (&timestamp.sec, &timestamp.nsec);
+  timestamp_ns = unix_time_now_nsec ();
 
   while (n_left_from > 0)
     {
@@ -480,7 +480,7 @@ upf_proxy_input (vlib_main_t * vm, vlib_node_runtime_t * node,
 		next = UPF_FORWARD_NEXT_DROP;
 
 	      flow_update_stats (vm, b, flow, is_ip4,
-				 timestamp, current_time);
+				 timestamp_ns, current_time);
 
 #undef IS_DL
 #undef IS_UL