Changeset 895:fbf77629cb7b in freeDiameter for libfdproto

Timestamp:

Nov 30, 2012, 8:44:10 AM (11 years ago)

Author:

Sebastien Decugis <sdecugis@freediameter.net>

Branch:

default

Phase:

public

Message:

Added received and sent timestamps in the messages; added logs on emission and reception

Location:

libfdproto

Files:

• messages.c (modified) (7 diffs)
• msg_log.c (modified) (2 diffs)

libfdproto/messages.c

@@ -128 +128 @@
         DiamId_t                 msg_src_id;            /* Diameter Id of the peer this message was received from. This string is malloc'd and must be freed */
         size_t                   msg_src_id_len;        /* cached length of this string */
-        struct timespec          msg_ts;                /* Timestamp associated with the message */
+        struct timespec          msg_ts_rcv;            /* Timestamp when this message was received from the network */
+        struct timespec          msg_ts_sent;           /* Timestamp when this message was sent to the network */
         
 };
@@ -678 +679 @@
 {
         int ret = 0;
+        char buftime[256];
+        size_t tsoffset = 0;
+        struct tm tm;
         
         CHECK_FCT( dump_add_str(outstr, offset, outlen, "%*sMSG: %p\n", INOBJHDRVAL, msg) );
@@ -684 +688 @@
                 CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "INVALID!\n", INOBJHDRVAL) );
                 return 0;
+        }
+        
+        if ((msg->msg_ts_rcv.tv_sec != 0) || (msg->msg_ts_rcv.tv_nsec != 0)) {
+                tsoffset += strftime(buftime + tsoffset, sizeof(buftime) - tsoffset, "%D,%T", localtime_r( &msg->msg_ts_rcv.tv_sec , &tm ));
+                tsoffset += snprintf(buftime + tsoffset, sizeof(buftime) - tsoffset, ".%6.6ld", msg->msg_ts_rcv.tv_nsec / 1000);
+                CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "Received: %s\n", INOBJHDRVAL, buftime) );
+        }
+        if ((msg->msg_ts_sent.tv_sec != 0) || (msg->msg_ts_sent.tv_nsec != 0)) {
+                tsoffset += strftime(buftime + tsoffset, sizeof(buftime) - tsoffset, "%D,%T", localtime_r( &msg->msg_ts_sent.tv_sec , &tm ));
+                tsoffset += snprintf(buftime + tsoffset, sizeof(buftime) - tsoffset, ".%6.6ld", msg->msg_ts_sent.tv_nsec / 1000);
+                CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "Sent    : %s\n", INOBJHDRVAL, buftime) );
         }
         
@@ -734 +749 @@
         if (!avp->avp_model) {
                 
-                CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(no model)\n", INOBJHDRVAL) );
+                CHECK_FCT( dump_add_str(outstr, offset, outlen, INOBJHDR "(no model resolved)\n", INOBJHDRVAL) );
                 
         } else {
@@ -826 +841 @@
         
         /* now really output this in one shot, so it is not interrupted */
-        fd_log_debug_fstr(fstr, "%s", outstr);
+        fd_log_debug_fstr(fstr, "%s\n", outstr);
         
         free(outstr);
@@ -838 +853 @@
                                 fd_log_debug_fstr(fstr, "Error while dumping %p\n", msg) );
         /* now really output this in one shot, so it is not interrupted */
-        fd_log_debug_fstr(fstr, "%s", outstr);
+        fd_log_debug_fstr(fstr, "%s\n", outstr);
         
         free(outstr);
@@ -1152 +1167 @@
         return 0;
 }
+
+int fd_msg_ts_set_recv( struct msg * msg, struct timespec * ts )
+{
+        TRACE_ENTRY("%p %p", msg, ts);
+        
+        /* Check we received valid parameters */
+        CHECK_PARAMS( CHECK_MSG(msg) );
+        CHECK_PARAMS( ts );
+        
+        memcpy(&msg->msg_ts_rcv, ts, sizeof(struct timespec));
+        return 0;
+}
+
+int fd_msg_ts_get_recv( struct msg * msg, struct timespec * ts )
+{
+        TRACE_ENTRY("%p %p", msg, ts);
+        
+        /* Check we received valid parameters */
+        CHECK_PARAMS( CHECK_MSG(msg) );
+        CHECK_PARAMS( ts );
+        
+        memcpy(ts, &msg->msg_ts_rcv, sizeof(struct timespec));
+        return 0;
+}
+
+int fd_msg_ts_set_sent( struct msg * msg, struct timespec * ts )
+{
+        TRACE_ENTRY("%p %p", msg, ts);
+        
+        /* Check we received valid parameters */
+        CHECK_PARAMS( CHECK_MSG(msg) );
+        CHECK_PARAMS( ts );
+        
+        memcpy(&msg->msg_ts_sent, ts, sizeof(struct timespec));
+        return 0;
+}
+
+int fd_msg_ts_get_sent( struct msg * msg, struct timespec * ts )
+{
+        TRACE_ENTRY("%p %p", msg, ts);
+        
+        /* Check we received valid parameters */
+        CHECK_PARAMS( CHECK_MSG(msg) );
+        CHECK_PARAMS( ts );
+        
+        memcpy(ts, &msg->msg_ts_sent, sizeof(struct timespec));
+        return 0;
+}
+
 
 /* Retrieve the session of the message */

libfdproto/msg_log.c

@@ -166 +166 @@
         (void)pthread_mutex_lock(&fd_log_lock);
         pthread_cleanup_push(fd_cleanup_mutex_silent, &fd_log_lock);
+        fprintf( fstr, "\n");
         va_start(ap, prefix_format);
         vfprintf( fstr, prefix_format, ap);
@@ -173 +174 @@
         (void)pthread_mutex_unlock(&fd_log_lock);
         
-        fd_log_debug_fstr(fstr, "\nLogged: %s\n\n", buftime);
+        fd_log_debug_fstr(fstr, "\n Logged: %s\n", buftime);
         
         /* And now the message itself */