Fix timestamps in Diagnostic Logs cluster to follow the spec. (projec…

…t-chip#24830)

* Fix timestamps in Diagnostic Logs cluster to follow the spec.

There were a few issues here:

1. We were using a monotonic timestamp, but setting the UTCTimeStamp in the
response payload.

2. We were using a millisecond timestamp, whereas the spec has microsecond ones.

Switch to using "time since server init" for the timestamp, put it in the
TimeSinceBoot field, and make sure it has the right units.

Also fixes the timestamps to actually be optional, per spec.

Fixes project-chip#24265

* Address review comment.

examples/log-source-app/log-source-common/log-source-app.matter

@@ -320,8 +320,8 @@ server cluster DiagnosticLogs = 50 {
   response struct RetrieveLogsResponse = 1 {
     LogsStatus status = 0;
     OCTET_STRING logContent = 1;
-    epoch_s UTCTimeStamp = 2;
-    INT32U timeSinceBoot = 3;
+    optional epoch_us UTCTimeStamp = 2;
+    optional systime_us timeSinceBoot = 3;
   }
 
   command RetrieveLogsRequest(RetrieveLogsRequestRequest): RetrieveLogsResponse = 0;

src/app/clusters/diagnostic-logs-server/diagnostic-logs-server.cpp

@@ -20,15 +20,20 @@
 #include <app/CommandHandlerInterface.h>
 #include <app/ConcreteCommandPath.h>
 #include <app/clusters/diagnostic-logs-server/diagnostic-logs-server.h>
+#include <app/server/Server.h>
 #include <app/util/af.h>
 #include <lib/support/BytesCircularBuffer.h>
+#include <lib/support/ScopedBuffer.h>
 
 #include <array>
 
+// We store our times as millisecond times, to save space.
+using TimeInBufferType = chip::System::Clock::Milliseconds32::rep;
+
 CHIP_ERROR DiagnosticLogsCommandHandler::PushLog(const chip::ByteSpan & payload)
 {
-    chip::System::Clock::Milliseconds32 now = chip::System::SystemClock().GetMonotonicTimestamp();
-    uint32_t timeMs                         = now.count();
+    auto now = std::chrono::duration_cast<chip::System::Clock::Milliseconds32>(chip::Server::GetInstance().TimeSinceInit());
+    TimeInBufferType timeMs = now.count();
     chip::ByteSpan payloadTime(reinterpret_cast<uint8_t *>(&timeMs), sizeof(timeMs));
     return mBuffer.Push(payloadTime, payload);
 }
@@ -56,27 +61,28 @@ void DiagnosticLogsCommandHandler::InvokeCommand(HandlerContext & handlerContext
                 }
 
                 size_t logSize = mBuffer.GetFrontSize();
-                chip::System::Clock::Milliseconds32::rep timeMs;
-                VerifyOrDie(logSize > sizeof(timeMs));
+                TimeInBufferType timeFromBuffer;
+                VerifyOrDie(logSize > sizeof(timeFromBuffer));
 
-                std::unique_ptr<uint8_t, decltype(&chip::Platform::MemoryFree)> buf(
-                    reinterpret_cast<uint8_t *>(chip::Platform::MemoryAlloc(logSize)), &chip::Platform::MemoryFree);
-                if (!buf)
+                chip::Platform::ScopedMemoryBuffer<uint8_t> buf;
+                if (!buf.Calloc(logSize))
                 {
                     response.status = chip::app::Clusters::DiagnosticLogs::LogsStatus::kBusy;
                     handlerContext.mCommandHandler.AddResponse(handlerContext.mRequestPath, response);
                     break;
                 }
 
                 // The entry is | time (4 bytes) | content (var size) |
-                chip::MutableByteSpan entry(buf.get(), logSize);
+                chip::MutableByteSpan entry(buf.Get(), logSize);
                 CHIP_ERROR err = mBuffer.ReadFront(entry);
                 VerifyOrDie(err == CHIP_NO_ERROR);
-                timeMs = *reinterpret_cast<decltype(timeMs) *>(buf.get());
+                memcpy(&timeFromBuffer, buf.Get(), sizeof(timeFromBuffer));
+
+                auto timestamp = chip::System::Clock::Milliseconds32(timeFromBuffer);
 
-                response.status       = chip::app::Clusters::DiagnosticLogs::LogsStatus::kSuccess;
-                response.logContent   = chip::ByteSpan(buf.get() + sizeof(timeMs), logSize - sizeof(timeMs));
-                response.UTCTimeStamp = timeMs;
+                response.status     = chip::app::Clusters::DiagnosticLogs::LogsStatus::kSuccess;
+                response.logContent = chip::ByteSpan(buf.Get() + sizeof(timeFromBuffer), logSize - sizeof(timeFromBuffer));
+                response.timeSinceBoot.SetValue(chip::System::Clock::Microseconds64(timestamp).count());
                 handlerContext.mCommandHandler.AddResponse(handlerContext.mRequestPath, response);
             }
             break;

src/app/server/Server.cpp

@@ -108,6 +108,8 @@ CHIP_ERROR Server::Init(const ServerInitParams & initParams)
     ChipLogProgress(AppServer, "Server initializing...");
     assertChipStackLockedByCurrentThread();
 
+    mInitTimestamp = System::SystemClock().GetMonotonicMicroseconds64();
+
     CASESessionManagerConfig caseSessionManagerConfig;
     DeviceLayer::DeviceInfoProvider * deviceInfoprovider = nullptr;
 

src/app/server/Server.h

@@ -55,6 +55,7 @@
 #include <protocols/secure_channel/SimpleSessionResumptionStorage.h>
 #endif
 #include <protocols/user_directed_commissioning/UserDirectedCommissioning.h>
+#include <system/SystemClock.h>
 #include <transport/SessionManager.h>
 #include <transport/TransportMgr.h>
 #include <transport/TransportMgrBase.h>
@@ -369,6 +370,11 @@ class Server
 
     void ScheduleFactoryReset();
 
+    System::Clock::Microseconds64 TimeSinceInit() const
+    {
+        return System::SystemClock().GetMonotonicMicroseconds64() - mInitTimestamp;
+    }
+
     static Server & GetInstance() { return sServer; }
 
 private:
@@ -566,6 +572,8 @@ class Server
     uint16_t mOperationalServicePort;
     uint16_t mUserDirectedCommissioningPort;
     Inet::InterfaceId mInterfaceId;
+
+    System::Clock::Microseconds64 mInitTimestamp;
 };
 
 } // namespace chip

src/app/zap-templates/common/override.js

@@ -71,6 +71,7 @@ function atomicType(arg)
   case 'percent100ths':
     return 'chip::Percent100ths';
   case 'epoch_us':
+  case 'systime_us':
     return 'uint64_t';
   case 'epoch_s':
   case 'utc':

src/app/zap-templates/zcl/data-model/chip/diagnostic-logs-cluster.xml

@@ -53,8 +53,8 @@ limitations under the License.
             <description>Response to the RetrieveLogsRequest</description>
             <arg name="Status" type="LogsStatus"/>
             <arg name="LogContent" type="OCTET_STRING"/>
-            <arg name="UTCTimeStamp" type="epoch_s"/>
-            <arg name="TimeSinceBoot" type="INT32U"/>
+            <arg name="UTCTimeStamp" type="epoch_us" optional="true"/>
+            <arg name="TimeSinceBoot" type="systime_us" optional="true"/>
         </command>
     </cluster>
 </configurator>

src/controller/data_model/controller-clusters.matter

@@ -1317,8 +1317,8 @@ client cluster DiagnosticLogs = 50 {
   response struct RetrieveLogsResponse = 1 {
     LogsStatus status = 0;
     OCTET_STRING logContent = 1;
-    epoch_s UTCTimeStamp = 2;
-    INT32U timeSinceBoot = 3;
+    optional epoch_us UTCTimeStamp = 2;
+    optional systime_us timeSinceBoot = 3;
   }
 
   command RetrieveLogsRequest(RetrieveLogsRequestRequest): RetrieveLogsResponse = 0;