# HG changeset patch
# User Edouard Tisserant
# Date 1359781262 -39600
# Node ID a8db48ec2c31dd301e8438b077f3f1311c0e34bf
# Parent  1499a4d225dbac3fe18ac907062865fd14ec2717
Added log messages time-stamping

diff -r 1499a4d225db -r a8db48ec2c31 ProjectController.py
--- a/ProjectController.py	Wed Jan 30 23:46:41 2013 +0100
+++ b/ProjectController.py	Sat Feb 02 16:01:02 2013 +1100
@@ -1089,9 +1089,10 @@
                         # depending on how user navigate in the panel
                         # and only ask for last one in follow mode
                     for msgidx in xrange(count-1, dump_end,-1):
-                        msg = self._connector.GetLogMessage(level, msgidx)
-                        if msg is not None :
-                            to_console.insert(0, LogLevels[level]+ ':#' + repr(msgidx) + ": " + msg)
+                        answer = self._connector.GetLogMessage(level, msgidx)
+                        if answer is not None :
+                            msg, tick, tv_sec, tv_nsec = answer 
+                            to_console.insert(0, LogLevels[level]+ ':#' + repr(msgidx) + ":\"" + msg + "\"" + str(map(int, (tick, tv_sec, tv_nsec))))
                         else:
                             to_console.insert(0, LogLevels[level]+ ': No log before #'+repr(msgidx))
                             break;
diff -r 1499a4d225db -r a8db48ec2c31 runtime/PLCObject.py
--- a/runtime/PLCObject.py	Wed Jan 30 23:46:41 2013 +0100
+++ b/runtime/PLCObject.py	Sat Feb 02 16:01:02 2013 +1100
@@ -97,14 +97,21 @@
             return 1;
 
     def GetLogMessage(self, level, msgid):
+        tick = ctypes.c_uint32()
+        tv_sec = ctypes.c_uint32()
+        tv_nsec = ctypes.c_uint32()
         if self._GetLogMessage is not None:
             maxsz = len(self._log_read_buffer)-1
-            sz = self._GetLogMessage(level, msgid, self._log_read_buffer, maxsz)
+            sz = self._GetLogMessage(level, msgid, 
+                self._log_read_buffer, maxsz,
+                ctypes.byref(tick),
+                ctypes.byref(tv_sec),
+                ctypes.byref(tv_nsec))
             if sz and sz <= maxsz:
                 self._log_read_buffer[sz] = '\x00'
-                return self._log_read_buffer.value
+                return self._log_read_buffer.value,tick.value,tv_sec.value,tv_nsec.value
         elif self._loading_error is not None and level==0:
-            return self._loading_error
+            return self._loading_error,0,0,0
         return None
 
     def _GetMD5FileName(self):
@@ -185,7 +192,7 @@
             self._log_read_buffer = ctypes.create_string_buffer(1<<14) #16K
             self._GetLogMessage = self.PLClibraryHandle.GetLogMessage
             self._GetLogMessage.restype = ctypes.c_uint32
-            self._GetLogMessage.argtypes = [ctypes.c_uint8, ctypes.c_uint32, ctypes.c_char_p, ctypes.c_uint32]
+            self._GetLogMessage.argtypes = [ctypes.c_uint8, ctypes.c_uint32, ctypes.c_char_p, ctypes.c_uint32, ctypes.POINTER(ctypes.c_uint32), ctypes.POINTER(ctypes.c_uint32), ctypes.POINTER(ctypes.c_uint32)]
 
             self._loading_error = None
             return True
diff -r 1499a4d225db -r a8db48ec2c31 targets/plc_debug.c
--- a/targets/plc_debug.c	Wed Jan 30 23:46:41 2013 +0100
+++ b/targets/plc_debug.c	Sat Feb 02 16:01:02 2013 +1100
@@ -343,8 +343,8 @@
 typedef struct {
     uint32_t msgidx;
     uint32_t msgsize;
-    /*XXX tick*/
-    /*XXX RTC*/
+    unsigned long tick;
+    IEC_TIME time;
 } mTail;
 
 /* Log cursor : 64b
@@ -357,12 +357,17 @@
 int LogMessage(uint8_t level, char* buf, uint32_t size){
     if(size < LOG_BUFFER_SIZE - sizeof(mTail)){
         uint32_t buffpos;
+        uint64_t new_cursor, old_cursor;
+
         mTail tail;
+        tail.msgsize = size;
+        tail.tick = __tick;
+        PLC_GetTime(&tail.time);
+
         /* We cannot increment both msg index and string pointer 
            in a single atomic operation but we can detect having been interrupted.
            So we can try with atomic compare and swap in a loop until operation
            succeeds non interrupted */
-        uint64_t new_cursor, old_cursor;
         do{
             old_cursor = LogCursor[level];
             buffpos = (uint32_t)old_cursor;
@@ -372,9 +377,6 @@
         }while(!__sync_bool_compare_and_swap(&LogCursor[level],old_cursor,new_cursor));
 
         copy_to_log(level, buffpos, buf, size);
-        tail.msgsize = size;
-        /*XXX tick*/
-        /*XXX RTC*/
         copy_to_log(level, (buffpos + size) & LOG_BUFFER_MASK, &tail, sizeof(mTail));
 
         return 1; /* Success */
@@ -390,7 +392,7 @@
 }
 
 /* Return message size and content */
-uint32_t GetLogMessage(uint8_t level, uint32_t msgidx, char* buf, uint32_t max_size){
+uint32_t GetLogMessage(uint8_t level, uint32_t msgidx, char* buf, uint32_t max_size, uint32_t* tick, uint32_t* tv_sec, uint32_t* tv_nsec){
     uint64_t cursor = LogCursor[level];
     if(cursor){
         /* seach cursor */
@@ -409,8 +411,12 @@
 
         if(tail.msgidx == msgidx){
             uint32_t sbuffpos = (stailpos - tail.msgsize ) & LOG_BUFFER_MASK; 
-            uint32_t totalsize = tail.msgsize; /*sizeof(mTail);*/
-            copy_from_log(level, sbuffpos, buf, totalsize > max_size ? max_size : totalsize);
+            uint32_t totalsize = tail.msgsize;
+            *tick = tail.tick; 
+            *tv_sec = tail.time.tv_sec; 
+            *tv_nsec = tail.time.tv_nsec; 
+            copy_from_log(level, sbuffpos, buf, 
+                          totalsize > max_size ? max_size : totalsize);
             return totalsize;
         }
     }