Matter add mini-profiler

CHANGELOG.md

@@ -6,6 +6,7 @@ All notable changes to this project will be documented in this file.
 ## [13.0.0.2]
 ### Added
 - Partition Wizard is now able to convert to safeboot from Shelly partition layout (#19034)
+- Matter add mini-profiler
 
 ### Breaking Changed
 

lib/libesp32/berry_matter/src/be_matter_module.c

@@ -204,6 +204,7 @@ extern const bclass be_class_Matter_TLV;   // need to declare it upfront because
 #include "solidify/solidified_Matter_Base38.h"
 #include "solidify/solidified_Matter_UI.h"
 #include "solidify/solidified_Matter_Device.h"
+#include "solidify/solidified_Matter_Profiler.h"
 
 #include "../generate/be_matter_certs.h"
 
@@ -287,6 +288,7 @@ module matter (scope: global, strings: weak) {
   sort, closure(matter_sort_closure)
   jitter, closure(matter_jitter_closure)
   inspect, closure(matter_inspect_closure)
+  Profiler, class(be_class_Matter_Profiler)
 
   // Status codes
   SUCCESS, int(0x00)

lib/libesp32/berry_matter/src/embedded/Matter_Device.be

@@ -35,6 +35,7 @@ class Matter_Device
   var plugins_config                  # map of JSON configuration for plugins
   var plugins_config_remotes          # map of information on each remote under "remotes" key, '{}' when empty
   var udp_server                      # `matter.UDPServer()` object
+  var profiler
   var message_handler                 # `matter.MessageHandler()` object
   var sessions                        # `matter.Session_Store()` objet
   var ui
@@ -80,6 +81,7 @@ class Matter_Device
       return
     end    # abort if SetOption 151 is not set
 
+    self.profiler = matter.Profiler()
     self.started = false
     self.tick = 0
     self.plugins = []
@@ -381,7 +383,7 @@ class Matter_Device
     if self.udp_server    return end        # already started
     if port == nil      port = 5540 end
     tasmota.log("MTR: Starting UDP server on port: " + str(port), 2)
-    self.udp_server = matter.UDPServer("", port)
+    self.udp_server = matter.UDPServer(self, "", port)
     self.udp_server.start(/ raw, addr, port -> self.msg_received(raw, addr, port))
   end
 

lib/libesp32/berry_matter/src/embedded/Matter_IM.be

@@ -330,6 +330,7 @@ class Matter_IM
   # returns `true` if processed, `false` if silently ignored,
   # or raises an exception
   def process_read_request(msg, val)
+    self.device.profiler.log("read_request_start")
     var query = matter.ReadRequestMessage().from_TLV(val)
     if query.attributes_requests != nil
       var ret = self._inner_process_read_request(msg.session, query)
@@ -383,6 +384,7 @@ class Matter_IM
     # import debug
     # structure is `ReadRequestMessage` 10.6.2 p.558
     # tasmota.log("MTR: IM:invoke_request processing start", 4)
+    self.device.profiler.log("invoke_request_start")
     var ctx = matter.Path()
     ctx.msg = msg
 

lib/libesp32/berry_matter/src/embedded/Matter_MessageHandler.be

@@ -76,6 +76,7 @@ class Matter_MessageHandler
   def msg_received(raw, addr, port)
     var ret = false
 
+    self.device.profiler.log("msg_received")
     try
       # tasmota.log("MTR: MessageHandler::msg_received raw="+raw.tohex(), 4)
       var frame = matter.Frame(self, raw, addr, port)
@@ -174,6 +175,7 @@ class Matter_MessageHandler
         elif protocol_id == 0x0001  # PROTOCOL_ID_INTERACTION_MODEL
           # dispatch to IM Protocol Messages
           ret = self.im.process_incoming(frame)
+          self.device.profiler.log("process_IM_end")
           # if `ret` is true, we have something to send
           if ret
             self.im.send_enqueued(self)
@@ -220,6 +222,7 @@ class Matter_MessageHandler
   #   msg.exchange_id:      exchange id (int)
   #   msg.local_session_id: local session (for logging)
   def send_response_frame(msg)
+    self.device.profiler.log("send_response_frame")
     self.device.msg_send(msg)
   end
 

lib/libesp32/berry_matter/src/embedded/Matter_Profiler.be

@@ -0,0 +1,73 @@
+#
+# Matter_Profiler.be - suppport for Matter profiler framework
+#
+# Copyright (C) 2023  Stephan Hadinger & Theo Arends
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation, either version 3 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+
+import matter
+
+#@ solidify:Matter_Profiler,weak
+
+#################################################################################
+# Matter_Profiler
+#
+# Used to store all the elements of the reponse to an attribute or command
+#################################################################################
+class Matter_Profiler
+  static var PREALLOCATED = 50
+  var millis
+  var names
+  var active
+
+  def init()
+    self.active = false
+    self.millis = list()
+    self.millis.resize(self.PREALLOCATED)
+    self.names = list()
+    self.names.resize(self.PREALLOCATED)
+  end
+
+  def set_active(v)
+    self.active = bool(v)
+  end
+
+  def start()
+    if !self.active  return end
+    self.millis.resize(0)
+    self.names.resize(0)
+    self.log("start")
+  end
+
+  def log(name)
+    if !self.active  return end
+    self.millis.push(tasmota.millis())
+    self.names.push(name)
+  end
+
+  def dump(loglevel)
+    if !self.active  return end
+    self.log("<--end-->")
+    tasmota.log("MTR: Profiler dump:", loglevel)
+    var origin = self.millis[0]
+    var idx = 1
+    while idx < size(self.millis)
+      tasmota.log(f"MTR:   {self.millis[idx] - origin:4i} '{self.names[idx]}'", loglevel)
+      idx += 1
+    end
+  end
+
+end
+matter.Profiler = Matter_Profiler

lib/libesp32/berry_matter/src/embedded/Matter_UDPServer.be

@@ -66,6 +66,7 @@ class Matter_UDPServer
   static var RETRIES = 5            # 6 transmissions max (5 retries) - 1 more than spec `MRP_MAX_TRANSMISSIONS` 4.11.8 p.146
   static var MAX_PACKETS_READ = 4   # read at most 4 packets per tick
   var addr, port                    # local addr and port
+  var device
   var listening                     # true if active
   var udp_socket
   var dispatch_cb                   # callback to call when a message is received
@@ -76,7 +77,8 @@ class Matter_UDPServer
   # Init UDP Server listening to `addr` and `port` (opt).
   #
   # By default, the server listens to `""` (all addresses) and port `5540`
-  def init(addr, port)
+  def init(device, addr, port)
+    self.device = device
     self.addr = addr ? addr : ""
     self.port = port ? port : 5540
     self.listening = false
@@ -121,19 +123,23 @@ class Matter_UDPServer
   # Then resend queued outgoing packets.
   def loop()
     # import debug
+    var profiler = self.device.profiler
     var packet_read = 0
     if self.udp_socket == nil  return end
     var packet = self.udp_socket.read()
     while packet != nil
       # self.packet = packet
+      profiler.start()
       packet_read += 1
       var from_addr = self.udp_socket.remote_ip
       var from_port = self.udp_socket.remote_port
       tasmota.log(format("MTR: UDP received from [%s]:%i", from_addr, from_port), 4)
       # tasmota.log("MTR: Perf/UDP_received = " + str(debug.counters()), 4)
       if self.dispatch_cb
+        profiler.log("udp_loop_dispatch")
         self.dispatch_cb(packet, from_addr, from_port)
       end
+      profiler.dump(2)
       # are we reading new packets?
       if packet_read < self.MAX_PACKETS_READ
         packet = self.udp_socket.read()