Live View stream not starting in ESP-Matter Camera example using ESP32-P4 Nano

[svn-matterize]

Environment

Hardware

• ESP32-P4 Nano Board: Waveshare ESP32-P4 Nano
• ESP32-C6

Repositories

• ESP-Matter Camera example:
  ESP-Matter Camera Example

• Amazon Kinesis Video Streams WebRTC SDK example:
  Amazon Kinesis Video Streams WebRTC SDK C

• Matter Camera Controller:
  Matter Camera Controller Example

---

Setup Procedure

1. ESP32-P4

Built and flashed the streaming-only example to ESP32-P4.

2. ESP32-C6

Built and flashed the esp-matter-camera example.

3. Linux Camera Controller

Built the camera-controller example and launched using:

./out/linux-x64-camera-controller/chip-camera-controller

4. Wi-Fi Connection

Connected ESP32-C6 manually using:

matter esp wifi connect <ssid> <password>

5. Pairing

Paired successfully using:

pairing onnetwork 1 20202021

6. Start Live View

Executed:

liveview start 1 --min-res-width 640 --min-res-height 480 --min-framerate 30

---

Observed Behavior

The live stream window does not open after executing the liveview start command.

Pairing succeeds successfully, but live streaming does not start.

---

Log from Camera-Controller

Click to expand code

>>> liveview start 1 --min-res-width 320 --min-res-height 240 --min-framerate 30
[1778160099.489] [164971:164971] [-] Command: liveview start 1 --min-res-width 320 --min-res-height 240 --min-framerate 30 
[1778160099.490] [164971:164973] [CAM] Run LiveViewStartCommand
[1778160099.490] [164971:164973] [CAM] Allocate a video stream on the camera device.
[1778160099.490] [164971:164973] [CAM] Sending VideoStreamAllocate to (node=0x0000000000000001, ep=1, usage=3)
[1778160099.490] [164971:164973] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1778160099.490] [164971:164973] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1778160099.490] [164971:164973] [DIS] Found an existing secure session to [1:0000000000000001]!
[1778160099.490] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1778160099.490] [164971:164973] [SVR] Sending command with Endpoint ID: 1, Command Type: 1
[1778160099.490] [164971:164973] [DMG] ICR moving to [AddingComm]
[1778160099.490] [164971:164973] [DMG] ICR moving to [AddedComma]
[1778160099.491] [164971:164973] [EM] <<< [E:28542i S:10843 M:204509644] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:109)
[1778160099.491] [164971:164973] [EM] ??1 [E:28542i S:10843 M:204509644] (S) Msg Retransmission to 1:0000000000000001 scheduled for 641ms from now [State:Idle II:500 AI:300 AT:4000]
[1778160099.491] [164971:164973] [DMG] ICR moving to [AwaitingRe]
[1778160099.648] [164971:164973] [EM] >>> [E:28542i S:10843 M:201392927 (Ack:204509644)] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:68)
[1778160099.648] [164971:164973] [EM] Found matching exchange: 28542i, Delegate: 0x78a7fc007bc8
[1778160099.648] [164971:164973] [EM] Rxd Ack; Removing MessageCounter:204509644 from Retrans Table on exchange 28542i
[1778160099.648] [164971:164973] [DMG] ICR moving to [ResponseRe]
[1778160099.648] [164971:164973] [DMG] InvokeResponseMessage =
[1778160099.648] [164971:164973] [DMG] {
[1778160099.648] [164971:164973] [DMG] 	suppressResponse = false, 
[1778160099.648] [164971:164973] [DMG] 	InvokeResponseIBs =
[1778160099.648] [164971:164973] [DMG] 	[
[1778160099.648] [164971:164973] [DMG] 		InvokeResponseIB =
[1778160099.648] [164971:164973] [DMG] 		{
[1778160099.648] [164971:164973] [DMG] 			CommandStatusIB =
[1778160099.648] [164971:164973] [DMG] 			{
[1778160099.648] [164971:164973] [DMG] 				CommandPathIB =
[1778160099.648] [164971:164973] [DMG] 				{
[1778160099.648] [164971:164973] [DMG] 					EndpointId = 0x1,
[1778160099.648] [164971:164973] [DMG] 					ClusterId = 0x551,
[1778160099.648] [164971:164973] [DMG] 					CommandId = 0x3,
[1778160099.648] [164971:164973] [DMG] 				},
[1778160099.648] [164971:164973] [DMG] 				
[1778160099.648] [164971:164973] [DMG] 				StatusIB =
[1778160099.648] [164971:164973] [DMG] 				{
[1778160099.648] [164971:164973] [DMG] 					status = 0xcf (DYNAMIC_CONSTRAINT_ERROR),
[1778160099.648] [164971:164973] [DMG] 				},
[1778160099.648] [164971:164973] [DMG] 				
[1778160099.648] [164971:164973] [DMG] 			},
[1778160099.648] [164971:164973] [DMG] 			
[1778160099.648] [164971:164973] [DMG] 		},
[1778160099.648] [164971:164973] [DMG] 		
[1778160099.648] [164971:164973] [DMG] 	],
[1778160099.648] [164971:164973] [DMG] 	
[1778160099.648] [164971:164973] [DMG] 	InteractionModelRevision = 12
[1778160099.648] [164971:164973] [DMG] },
[1778160099.648] [164971:164973] [DMG] Received Command Response Status for Endpoint=1 Cluster=0x0000_0551 Command=0x0000_0003 Status=0xcf
[1778160099.648] [164971:164973] [CAM] AVStreamManagement: OnError. Error: IM Error 0x000005CF: General error: 0xcf (DYNAMIC_CONSTRAINT_ERROR)
[1778160099.648] [164971:164973] [DMG] ICR moving to [AwaitingDe]
[1778160099.648] [164971:164973] [CAM] AVStreamManagement: OnDone.
[1778160099.648] [164971:164973] [CAM] AVStreamManagement: Command VideoStreamAllocate has been successfully processed.
[1778160099.648] [164971:164973] [EM] <<< [E:28542i S:10843 M:204509645 (Ack:201392927)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1778160099.648] [164971:164973] [EM] Flushed pending ack for MessageCounter:201392927 on exchange 28542i

>>> liveview start 1 --min-res-width 640 --min-res-height 480 --min-framerate 30
[1778160117.791] [164971:164971] [-] Command: liveview start 1 --min-res-width 640 --min-res-height 480 --min-framerate 30 
[1778160117.791] [164971:164973] [CAM] Run LiveViewStartCommand
[1778160117.791] [164971:164973] [CAM] Allocate a video stream on the camera device.
[1778160117.792] [164971:164973] [CAM] Sending VideoStreamAllocate to (node=0x0000000000000001, ep=1, usage=3)
[1778160117.792] [164971:164973] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1778160117.792] [164971:164973] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1778160117.792] [164971:164973] [DIS] Found an existing secure session to [1:0000000000000001]!
[1778160117.792] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1778160117.792] [164971:164973] [SVR] Sending command with Endpoint ID: 1, Command Type: 1
[1778160117.792] [164971:164973] [DMG] ICR moving to [AddingComm]
[1778160117.792] [164971:164973] [DMG] ICR moving to [AddedComma]
[1778160117.792] [164971:164973] [EM] <<< [E:28543i S:10843 M:204509646] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:110)
[1778160117.792] [164971:164973] [EM] ??1 [E:28543i S:10843 M:204509646] (S) Msg Retransmission to 1:0000000000000001 scheduled for 677ms from now [State:Idle II:500 AI:300 AT:4000]
[1778160117.792] [164971:164973] [DMG] ICR moving to [AwaitingRe]
[1778160118.143] [164971:164973] [EM] >>> [E:28543i S:10843 M:201392928 (Ack:204509646)] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:68)
[1778160118.143] [164971:164973] [EM] Found matching exchange: 28543i, Delegate: 0x78a7fc007bc8
[1778160118.143] [164971:164973] [EM] Rxd Ack; Removing MessageCounter:204509646 from Retrans Table on exchange 28543i
[1778160118.143] [164971:164973] [DMG] ICR moving to [ResponseRe]
[1778160118.143] [164971:164973] [DMG] InvokeResponseMessage =
[1778160118.143] [164971:164973] [DMG] {
[1778160118.143] [164971:164973] [DMG] 	suppressResponse = false, 
[1778160118.143] [164971:164973] [DMG] 	InvokeResponseIBs =
[1778160118.143] [164971:164973] [DMG] 	[
[1778160118.143] [164971:164973] [DMG] 		InvokeResponseIB =
[1778160118.143] [164971:164973] [DMG] 		{
[1778160118.143] [164971:164973] [DMG] 			CommandDataIB =
[1778160118.143] [164971:164973] [DMG] 			{
[1778160118.143] [164971:164973] [DMG] 				CommandPathIB =
[1778160118.143] [164971:164973] [DMG] 				{
[1778160118.143] [164971:164973] [DMG] 					EndpointId = 0x1,
[1778160118.143] [164971:164973] [DMG] 					ClusterId = 0x551,
[1778160118.143] [164971:164973] [DMG] 					CommandId = 0x4,
[1778160118.143] [164971:164973] [DMG] 				},
[1778160118.143] [164971:164973] [DMG] 				
[1778160118.143] [164971:164973] [DMG] 				CommandFields = 
[1778160118.143] [164971:164973] [DMG] 				{
[1778160118.143] [164971:164973] [DMG] 					0x0 = 2 (unsigned), 
[1778160118.143] [164971:164973] [DMG] 				},
[1778160118.143] [164971:164973] [DMG] 			},
[1778160118.143] [164971:164973] [DMG] 			
[1778160118.143] [164971:164973] [DMG] 		},
[1778160118.143] [164971:164973] [DMG] 		
[1778160118.143] [164971:164973] [DMG] 	],
[1778160118.143] [164971:164973] [DMG] 	
[1778160118.143] [164971:164973] [DMG] 	InteractionModelRevision = 12
[1778160118.143] [164971:164973] [DMG] },
[1778160118.143] [164971:164973] [DMG] Received Command Response Data, Endpoint=1 Cluster=0x0000_0551 Command=0x0000_0004
[1778160118.143] [164971:164973] [CAM] AVStreamManagement: OnResponse.
[1778160118.143] [164971:164973] [CAM] Command Response received.
[1778160118.143] [164971:164973] [CAM] Handle VideoStreamAllocateResponse command.
[1778160118.143] [164971:164973] [CAM] DecodableType fields:
[1778160118.143] [164971:164973] [CAM]   videoStreamId: 2
[1778160118.143] [164971:164973] [CAM] DeviceManager: Initiating WebRTC session for node=0x0000000000000001
[1778160118.143] [164971:164973] [CAM] Attempting to establish WebRTC connection to node 0x0000000000000001 on endpoint 0x1
[1778160118.143] [164971:164973] [CAM] Disconnecting WebRTC session
[1778160118.143] [164971:164973] [CAM] Commissioner is on Fabric ID 0x0000000000000001
[1778160118.143] [164971:164973] [CAM] WebRTCProviderClient: Initialized with PeerId=0x0000000000000001, endpoint=1
[1778160118.152] [164971:164973] [CAM] Generate and set the SDP
[1778160118.152] [164971:164994] [CAM] Local Description:
[1778160118.152] [164971:164994] [CAM] v=0
o=rtc 2059861608 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE video audio
a=group:LS video audio
a=msid-semantic:WMS *
a=ice-options:ice2,trickle
a=fingerprint:sha-256 2B:5A:F1:09:5C:2F:08:58:43:92:52:45:71:DB:17:AF:AC:5B:08:07:5E:70:5C:D3:0B:1E:8D:98:BE:BD:45:0C
m=video 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
b=AS:3000
a=mid:video
a=recvonly
a=rtcp-mux
a=rtpmap:96 H264/90000
a=rtcp-fb:96 nack
a=rtcp-fb:96 nack pli
a=rtcp-fb:96 goog-remb
a=fmtp:96 profile-level-id=42e01f;packetization-mode=1;level-asymmetry-allowed=1
a=setup:actpass
a=ice-ufrag:hHJR
a=ice-pwd:O8MtESLy8xP4pLFXLOtzys
m=audio 9 UDP/TLS/RTP/SAVPF 111
c=IN IP4 0.0.0.0
b=AS:64000
a=mid:audio
a=recvonly
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10;maxaveragebitrate=96000;stereo=1;sprop-stereo=1;useinbandfec=1
a=setup:actpass
a=ice-ufrag:hHJR
a=ice-pwd:O8MtESLy8xP4pLFXLOtzys

[1778160118.153] [164971:164994] [CAM] Extracted 0 candidates from SDP description
[1778160118.153] [164971:164994] [CAM] [PeerConnection Gathering State: InProgress]
[1778160118.153] [164971:164998] [CAM] Local Candidate:
[1778160118.153] [164971:164998] [CAM] a=candidate:3 1 UDP 2116025855 fd00:172:172:172::f3d2 40933 typ host
[1778160118.153] [164971:164998] [CAM]   mid: video, mlineIndex: -1
[1778160118.153] [164971:164998] [CAM] Local Candidate:
[1778160118.153] [164971:164998] [CAM] a=candidate:4 1 UDP 2116025599 fd1b:40f7:e390:4592:7f49:b191:bf60:9031 40933 typ host
[1778160118.153] [164971:164998] [CAM]   mid: video, mlineIndex: -1
[1778160118.153] [164971:164998] [CAM] Local Candidate:
[1778160118.153] [164971:164998] [CAM] a=candidate:1 1 UDP 2114977791 172.172.172.172 40933 typ host
[1778160118.153] [164971:164998] [CAM]   mid: video, mlineIndex: -1
[1778160118.153] [164971:164999] [CAM] Local Candidate:
[1778160118.153] [164971:164999] [CAM] a=candidate:2 1 UDP 2114977535 141.141.141.107 40933 typ host
[1778160118.153] [164971:164999] [CAM]   mid: video, mlineIndex: -1
[1778160118.153] [164971:164999] [CAM] [PeerConnection State: Connecting]
[1778160118.191] [164971:165002] [CAM] Local Candidate:
[1778160118.191] [164971:165002] [CAM] a=candidate:5 1 UDP 1678769151 122.174.39.67 40933 typ srflx raddr 0.0.0.0 rport 0
[1778160118.191] [164971:165002] [CAM]   mid: video, mlineIndex: -1
[1778160119.153] [164971:164973] [CAM] Using ProvideOffer for WebRTC session establishment
[1778160119.153] [164971:164973] [CAM] Sending ProvideOffer command to the peer device
[1778160119.153] [164971:164973] [CAM] Tracking stream ID 2 for WebRTC session
[1778160119.153] [164971:164973] [CAM] Sending ProvideOffer to node 0000000000000001
[1778160119.153] [164971:164973] [CAM] WebRTCProviderClient moving to [ Connecting ]
[1778160119.153] [164971:164973] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1778160119.153] [164971:164973] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1778160119.153] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1778160119.154] [164971:164973] [DIS] Lookup started for CA613BE0EC918697-0000000000000001
[1778160119.154] [164971:164973] [DMG] ICR moving to [AwaitingDe]
[1778160119.154] [164971:164973] [CAM] AVStreamManagement: OnDone.
[1778160119.154] [164971:164973] [CAM] AVStreamManagement: Command VideoStreamAllocate has been successfully processed.
[1778160119.154] [164971:164973] [EM] <<< [E:28543i S:10843 M:204509647 (Ack:201392928)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1778160119.154] [164971:164973] [EM] Flushed pending ack for MessageCounter:201392928 on exchange 28543i
[1778160119.154] [164971:164973] [IN] Received a duplicate message with MessageCounter:201392928 on exchange 28543i
[1778160119.154] [164971:164973] [EM] >>> [E:28543i S:10843 M:201392928 (Ack:204509646)] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:68)
[1778160119.154] [164971:164973] [EM] Generating StandaloneAck via exchange: 28543i
[1778160119.154] [164971:164973] [EM] Forcing tx of solitary ack for duplicate MessageCounter:201392928 on exchange 28543i
[1778160119.154] [164971:164973] [EM] <<< [E:28543i S:10843 M:204509648 (Ack:201392928)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1778160119.154] [164971:164973] [IN] Received a duplicate message with MessageCounter:201392928 on exchange 28543i
[1778160119.154] [164971:164973] [EM] >>> [E:28543i S:10843 M:201392928 (Ack:204509646)] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:68)
[1778160119.154] [164971:164973] [EM] Generating StandaloneAck via exchange: 28543i
[1778160119.154] [164971:164973] [EM] Forcing tx of solitary ack for duplicate MessageCounter:201392928 on exchange 28543i
[1778160119.154] [164971:164973] [EM] <<< [E:28543i S:10843 M:204509649 (Ack:201392928)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1778160119.265] [164971:164973] [DIS] UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540: new best score: 7 (for CA613BE0EC918697-0000000000000001)
[1778160119.265] [164971:164973] [DIS] Lookup clearing interface for non LL address
[1778160119.265] [164971:164973] [DIS] UDP:[fd1b:40f7:e390:4592:e6b3:23ff:fe90:8844%wlp3s0]:5540: new best score: 5 (for CA613BE0EC918697-0000000000000001)
[1778160119.265] [164971:164973] [DIS] Lookup clearing interface for non LL address
[1778160119.265] [164971:164973] [DIS] UDP:141.141.141.108%wlp3s0:5540: new best score: 2 (for CA613BE0EC918697-0000000000000001)
[1778160119.266] [164971:164973] [DIS] Checking node lookup status for CA613BE0EC918697-0000000000000001 after 113 ms
[1778160119.266] [164971:164973] [DIS] Keeping DNSSD lookup active
[1778160119.266] [164971:164973] [DIS] UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540: score has not improved: 7 (for CA613BE0EC918697-0000000000000001)
[1778160119.266] [164971:164973] [DIS] Lookup clearing interface for non LL address
[1778160119.266] [164971:164973] [DIS] UDP:[fd1b:40f7:e390:4592:e6b3:23ff:fe90:8844%wlp3s0]:5540: score has not improved: 5 (for CA613BE0EC918697-0000000000000001)
[1778160119.266] [164971:164973] [DIS] Lookup clearing interface for non LL address
[1778160119.266] [164971:164973] [DIS] UDP:141.141.141.108%wlp3s0:5540: score has not improved: 2 (for CA613BE0EC918697-0000000000000001)
[1778160119.266] [164971:164973] [DIS] Checking node lookup status for CA613BE0EC918697-0000000000000001 after 113 ms
[1778160119.266] [164971:164973] [DIS] Keeping DNSSD lookup active
[1778160119.353] [164971:164973] [DIS] Checking node lookup status for CA613BE0EC918697-0000000000000001 after 200 ms
[1778160119.353] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540 while in state 2
[1778160119.353] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1778160119.353] [164971:164973] [IN] SecureSession[0x78a7fc03e7f0]: Allocated Type:2 LSID:10844
[1778160119.353] [164971:164973] [SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1778160119.354] [164971:164973] [IN] Connecting over TCP with peer at TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540.
[1778160119.354] [164971:164973] [IN] Connecting to peer TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540.
[1778160119.354] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1778160119.684] [164971:164973] [IN] Connection established successfully with TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540.
[1778160119.684] [164971:164973] [SC] TCP Connection established with TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540 before session establishment
[1778160119.685] [164971:164973] [EM] <<< [E:28544i S:0 M:221023762] (U) Msg TX from 3CC6BB400A2B1F39 to 0:0000000000000000 [0000] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:234)
[1778160119.685] [164971:164973] [SC] Sent Sigma1 msg to <0000000000000001, 1> [II:500ms AI:300ms AT:4000ms]
[1778160119.740] [164971:164973] [EM] >>> [E:28544i S:0 M:148084934] (U) Msg RX from 0:0000000000000000 [0000] to 3CC6BB400A2B1F39 --- Type 0000:33 (SecureChannel:CASE_Sigma2Resume) (B:96)
[1778160119.740] [164971:164973] [EM] Found matching exchange: 28544i, Delegate: 0x78a7fc026168
[1778160119.740] [164971:164973] [SC] Received Sigma2Resume msg
[1778160119.740] [164971:164973] [SC] Found MRP parameters in the message
[1778160119.741] [164971:164973] [SC] Peer <0000000000000001, 1> assigned session ID 60203
[1778160119.742] [164971:164973] [SC] Sending status report. Protocol code 0, exchange 28544
[1778160119.742] [164971:164973] [EM] <<< [E:28544i S:0 M:221023763] (U) Msg TX from 3CC6BB400A2B1F39 to 0:0000000000000000 [0000] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
[1778160119.742] [164971:164973] [SC] SecureSession[0x78a7fc03e7f0, LSID:10844]: State change 'kEstablishing' --> 'kActive'
[1778160119.742] [164971:164973] [IN] SecureSession[0x78a7fc03e7f0]: Activated - Type:2 LSID:10844
[1778160119.742] [164971:164973] [IN] New secure session activated for device <0000000000000001, 1>, LSID:10844 PSID:60203!
[1778160119.742] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1778160119.742] [164971:164973] [CAM] CASE session established, sending WebRTCTransportProvider command...
[1778160119.742] [164971:164973] [CAM] Sending command with Endpoint ID: 1, Command Type: 2
[1778160119.742] [164971:164973] [DMG] ICR moving to [AddingComm]
[1778160119.742] [164971:164973] [DMG] ICR moving to [AddedComma]
[1778160119.742] [164971:164973] [EM] <<< [E:28545i S:10844 M:171433500] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:973)
[1778160119.742] [164971:164973] [DMG] ICR moving to [AwaitingRe]
[1778160119.742] [164971:164973] [CAM] WebRTCProviderClient moving to [ AwaitingResponse ]
[1778160119.942] [164971:164973] [EM] >>> [E:28545i S:10844 M:18303003] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:67)
[1778160119.942] [164971:164973] [EM] Found matching exchange: 28545i, Delegate: 0x78a7fc007bc8
[1778160119.942] [164971:164973] [DMG] ICR moving to [ResponseRe]
[1778160119.942] [164971:164973] [DMG] InvokeResponseMessage =
[1778160119.942] [164971:164973] [DMG] {
[1778160119.942] [164971:164973] [DMG] 	suppressResponse = false, 
[1778160119.942] [164971:164973] [DMG] 	InvokeResponseIBs =
[1778160119.942] [164971:164973] [DMG] 	[
[1778160119.942] [164971:164973] [DMG] 		InvokeResponseIB =
[1778160119.942] [164971:164973] [DMG] 		{
[1778160119.942] [164971:164973] [DMG] 			CommandDataIB =
[1778160119.942] [164971:164973] [DMG] 			{
[1778160119.942] [164971:164973] [DMG] 				CommandPathIB =
[1778160119.942] [164971:164973] [DMG] 				{
[1778160119.942] [164971:164973] [DMG] 					EndpointId = 0x1,
[1778160119.942] [164971:164973] [DMG] 					ClusterId = 0x553,
[1778160119.942] [164971:164973] [DMG] 					CommandId = 0x3,
[1778160119.942] [164971:164973] [DMG] 				},
[1778160119.942] [164971:164973] [DMG] 				
[1778160119.942] [164971:164973] [DMG] 				CommandFields = 
[1778160119.942] [164971:164973] [DMG] 				{
[1778160119.942] [164971:164973] [DMG] 					0x0 = 0 (unsigned), 
[1778160119.942] [164971:164973] [DMG] 					0x1 = 2 (unsigned), 
[1778160119.942] [164971:164973] [DMG] 				},
[1778160119.942] [164971:164973] [DMG] 			},
[1778160119.942] [164971:164973] [DMG] 			
[1778160119.942] [164971:164973] [DMG] 		},
[1778160119.942] [164971:164973] [DMG] 		
[1778160119.942] [164971:164973] [DMG] 	],
[1778160119.942] [164971:164973] [DMG] 	
[1778160119.942] [164971:164973] [DMG] 	InteractionModelRevision = 12
[1778160119.942] [164971:164973] [DMG] },
[1778160119.942] [164971:164973] [DMG] Received Command Response Data, Endpoint=1 Cluster=0x0000_0553 Command=0x0000_0003
[1778160119.942] [164971:164973] [CAM] WebRTCProviderClient: OnResponse received for cluster: 0x553 command: 0x3
[1778160119.942] [164971:164973] [CAM] Processing ProvideOfferResponse
[1778160119.942] [164971:164973] [CAM] WebRTCProviderClient::HandleProvideOfferResponse.
[1778160119.942] [164971:164973] [CAM] WebRTCProviderClient moving to [ AwaitingAnswer ]
[1778160119.942] [164971:164973] [DMG] ICR moving to [AwaitingDe]
[1778160119.942] [164971:164973] [CAM] WebRTCProviderClient: OnDone for command 2.
[1778160121.215] [164971:164973] [EM] >>> [E:35975r S:10844 M:18303004] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:08 (IM:InvokeCommandRequest) (B:2034)
[1778160121.215] [164971:164973] [EM] Handling via exchange: 35975r, Delegate: 0x58cd941d2f68
[1778160121.215] [164971:164973] [DMG] InvokeRequestMessage =
[1778160121.215] [164971:164973] [DMG] {
[1778160121.215] [164971:164973] [DMG] 	suppressResponse = false, 
[1778160121.215] [164971:164973] [DMG] 	timedRequest = false, 
[1778160121.215] [164971:164973] [DMG] 	InvokeRequests =
[1778160121.215] [164971:164973] [DMG] 	[
[1778160121.215] [164971:164973] [DMG] 		CommandDataIB =
[1778160121.215] [164971:164973] [DMG] 		{
[1778160121.215] [164971:164973] [DMG] 			CommandPathIB =
[1778160121.215] [164971:164973] [DMG] 			{
[1778160121.215] [164971:164973] [DMG] 				EndpointId = 0x1,
[1778160121.215] [164971:164973] [DMG] 				ClusterId = 0x554,
[1778160121.215] [164971:164973] [DMG] 				CommandId = 0x1,
[1778160121.215] [164971:164973] [DMG] 			},
[1778160121.215] [164971:164973] [DMG] 			
[1778160121.215] [164971:164973] [DMG] 			CommandFields = 
[1778160121.215] [164971:164973] [DMG] 			{
[1778160121.215] [164971:164973] [DMG] 				0x0 = 0 (unsigned), 
[1778160121.215] [164971:164973] [DMG] 				0x1 = ... (char string too long: 1967 chars) ...
[1778160121.215] [164971:164973] [DMG] 			},
[1778160121.215] [164971:164973] [DMG] 		},
[1778160121.215] [164971:164973] [DMG] 		
[1778160121.215] [164971:164973] [DMG] 	],
[1778160121.215] [164971:164973] [DMG] 	
[1778160121.215] [164971:164973] [DMG] 	InteractionModelRevision = 12
[1778160121.215] [164971:164973] [DMG] },
[1778160121.216] [164971:164973] [DMG] AccessControl: checking f=1 a=c s=0x0000000000000001 t= c=0x0000_0554 e=1 p=o r=i
[1778160121.216] [164971:164973] [DMG] AccessControl: allowed (delegate)
[1778160121.216] [164971:164973] [DMG] Received command for Endpoint=1 Cluster=0x0000_0554 Command=0x0000_0001
[1778160121.216] [164971:164973] [CAM] WebRTCRequestorDelegate::HandleAnswer
[1778160121.216] [164971:164973] [CAM] WebRTCManager::HandleAnswer
[1778160121.216] [164971:164973] [CAM] Answer command received for WebRTC session ID: 0
[1778160121.216] [164971:164973] [CAM] WebRTCProviderClient moving to [ Idle ]
[1778160121.217] [164971:164973] [DMG] Command handler moving to [NewRespons]
[1778160121.217] [164971:164973] [DMG] Command handler moving to [ Preparing]
[1778160121.217] [164971:164973] [DMG] Command handler moving to [AddingComm]
[1778160121.217] [164971:164973] [DMG] Command handler moving to [AddedComma]
[1778160121.217] [164971:164973] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 1
[1778160121.217] [164971:164973] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 0
[1778160121.217] [164971:164973] [DMG] Command handler moving to [AwaitingDe]
[1778160121.217] [164971:164973] [EM] <<< [E:35975r S:10844 M:171433501] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:09 (IM:InvokeCommandResponse) (B:64)
[1778160121.217] [164971:164973] [DMG] Command response sender moving to [AllInvokeR]
[1778160121.516] [164971:164973] [CAM] Sending ProvideICECandidates command to the peer device
[1778160121.516] [164971:164973] [CAM] Sending ProvideICECandidates to node 0000000000000001
[1778160121.516] [164971:164973] [CAM] WebRTCProviderClient moving to [ Connecting ]
[1778160121.516] [164971:164973] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1778160121.516] [164971:164973] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1778160121.516] [164971:164973] [DIS] Found an existing secure session to [1:0000000000000001]!
[1778160121.516] [164971:164973] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1778160121.516] [164971:164973] [CAM] CASE session established, sending WebRTCTransportProvider command...
[1778160121.516] [164971:164973] [CAM] Sending command with Endpoint ID: 1, Command Type: 4
[1778160121.516] [164971:164973] [DMG] ICR moving to [AddingComm]
[1778160121.516] [164971:164973] [DMG] ICR moving to [AddedComma]
[1778160121.516] [164971:164973] [EM] <<< [E:28546i S:10844 M:171433502] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:498)
[1778160121.516] [164971:164973] [DMG] ICR moving to [AwaitingRe]
[1778160121.516] [164971:164973] [CAM] WebRTCProviderClient moving to [ AwaitingResponse ]
[1778160121.516] [164971:164973] [CAM] Sent 5 ICE candidate(s)
[1778160121.516] [164971:164973] [CAM] Sent 5 ICE candidate(s), clearing list
[1778160121.837] [164971:164995] [CAM] [PeerConnection State: Connected]
[1778160121.837] [164971:164995] [CAM] WebRTC session established for stream ID: 2
[1778160121.837] [164971:164995] [CAM] Starting video stream process for stream ID: 2
[1778160121.838] [164971:164995] [CAM] Video stream process started with PID: 165014
[1778160121.898] [164971:164973] [EM] >>> [E:28546i S:10844 M:18303005] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:64)
[1778160121.898] [164971:164973] [EM] Found matching exchange: 28546i, Delegate: 0x78a7fc0090f8
[1778160121.898] [164971:164973] [DMG] ICR moving to [ResponseRe]
[1778160121.898] [164971:164973] [DMG] InvokeResponseMessage =
[1778160121.898] [164971:164973] [DMG] {
[1778160121.898] [164971:164973] [DMG] 	suppressResponse = false, 
[1778160121.898] [164971:164973] [DMG] 	InvokeResponseIBs =
[1778160121.898] [164971:164973] [DMG] 	[
[1778160121.898] [164971:164973] [DMG] 		InvokeResponseIB =
[1778160121.898] [164971:164973] [DMG] 		{
[1778160121.898] [164971:164973] [DMG] 			CommandStatusIB =
[1778160121.898] [164971:164973] [DMG] 			{
[1778160121.898] [164971:164973] [DMG] 				CommandPathIB =
[1778160121.898] [164971:164973] [DMG] 				{
[1778160121.898] [164971:164973] [DMG] 					EndpointId = 0x1,
[1778160121.898] [164971:164973] [DMG] 					ClusterId = 0x553,
[1778160121.898] [164971:164973] [DMG] 					CommandId = 0x5,
[1778160121.898] [164971:164973] [DMG] 				},
[1778160121.898] [164971:164973] [DMG] 				
[1778160121.898] [164971:164973] [DMG] 				StatusIB =
[1778160121.898] [164971:164973] [DMG] 				{
[1778160121.898] [164971:164973] [DMG] 					status = 0x00 (SUCCESS),
[1778160121.898] [164971:164973] [DMG] 				},
[1778160121.898] [164971:164973] [DMG] 				
[1778160121.898] [164971:164973] [DMG] 			},
[1778160121.898] [164971:164973] [DMG] 			
[1778160121.898] [164971:164973] [DMG] 		},
[1778160121.898] [164971:164973] [DMG] 		
[1778160121.898] [164971:164973] [DMG] 	],
[1778160121.898] [164971:164973] [DMG] 	
[1778160121.898] [164971:164973] [DMG] 	InteractionModelRevision = 12
[1778160121.898] [164971:164973] [DMG] },
[1778160121.898] [164971:164973] [DMG] Received Command Response Status for Endpoint=1 Cluster=0x0000_0553 Command=0x0000_0005 Status=0x0
[1778160121.898] [164971:164973] [CAM] WebRTCProviderClient: OnResponse received for cluster: 0x553 command: 0x5
[1778160121.898] [164971:164973] [CAM] Unexpected command ID: 0x5
[1778160121.898] [164971:164973] [DMG] ICR moving to [AwaitingDe]
[1778160121.898] [164971:164973] [CAM] WebRTCProviderClient: OnDone for command 4.
[1778160121.898] [164971:164973] [CAM] WebRTCProviderClient moving to [ Idle ]
[1778160121.940] [164971:164973] [EM] >>> [E:35976r S:10844 M:18303006] (S) Msg RX from 1:0000000000000001 [8697] to 000000000001B669 --- Type 0001:08 (IM:InvokeCommandRequest) (B:305)
[1778160121.940] [164971:164973] [EM] Handling via exchange: 35976r, Delegate: 0x58cd941d2f68
[1778160121.940] [164971:164973] [DMG] InvokeRequestMessage =
[1778160121.940] [164971:164973] [DMG] {
[1778160121.940] [164971:164973] [DMG] 	suppressResponse = false, 
[1778160121.940] [164971:164973] [DMG] 	timedRequest = false, 
[1778160121.940] [164971:164973] [DMG] 	InvokeRequests =
[1778160121.940] [164971:164973] [DMG] 	[
[1778160121.940] [164971:164973] [DMG] 		CommandDataIB =
[1778160121.940] [164971:164973] [DMG] 		{
[1778160121.940] [164971:164973] [DMG] 			CommandPathIB =
[1778160121.940] [164971:164973] [DMG] 			{
[1778160121.940] [164971:164973] [DMG] 				EndpointId = 0x1,
[1778160121.940] [164971:164973] [DMG] 				ClusterId = 0x554,
[1778160121.940] [164971:164973] [DMG] 				CommandId = 0x2,
[1778160121.940] [164971:164973] [DMG] 			},
[1778160121.940] [164971:164973] [DMG] 			
[1778160121.940] [164971:164973] [DMG] 			CommandFields = 
[1778160121.940] [164971:164973] [DMG] 			{
[1778160121.940] [164971:164973] [DMG] 				0x0 = 0 (unsigned), 
[1778160121.940] [164971:164973] [DMG] 				0x1 = [
[1778160121.940] [164971:164973] [DMG] 						
[1778160121.940] [164971:164973] [DMG] 					{
[1778160121.940] [164971:164973] [DMG] 						0x0 = "candidate:0 1 udp 2130706431 141.141.141.108 56571 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999" (111 chars), 
[1778160121.940] [164971:164973] [DMG] 						0x1 = NULL
[1778160121.940] [164971:164973] [DMG] 						0x2 = NULL
[1778160121.940] [164971:164973] [DMG] 					},
[1778160121.940] [164971:164973] [DMG] 					{
[1778160121.940] [164971:164973] [DMG] 						0x0 = "candidate:1 1 udp 1694498815 122.174.39.67 56572 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999" (110 chars), 
[1778160121.940] [164971:164973] [DMG] 						0x1 = NULL
[1778160121.940] [164971:164973] [DMG] 						0x2 = NULL
[1778160121.940] [164971:164973] [DMG] 					},
[1778160121.940] [164971:164973] [DMG] 				],
[1778160121.940] [164971:164973] [DMG] 			},
[1778160121.940] [164971:164973] [DMG] 		},
[1778160121.940] [164971:164973] [DMG] 		
[1778160121.940] [164971:164973] [DMG] 	],
[1778160121.940] [164971:164973] [DMG] 	
[1778160121.940] [164971:164973] [DMG] 	InteractionModelRevision = 12
[1778160121.940] [164971:164973] [DMG] },
[1778160121.941] [164971:164973] [DMG] AccessControl: checking f=1 a=c s=0x0000000000000001 t= c=0x0000_0554 e=1 p=o r=i
[1778160121.941] [164971:164973] [DMG] AccessControl: allowed (delegate)
[1778160121.941] [164971:164973] [DMG] Received command for Endpoint=1 Cluster=0x0000_0554 Command=0x0000_0002
[1778160121.941] [164971:164973] [CAM] WebRTCRequestorDelegate::HandleICECandidates
[1778160121.941] [164971:164973] [CAM] WebRTCManager::HandleICECandidates
[1778160121.941] [164971:164973] [CAM] Applying candidate: candidate:0 1 udp 2130706431 141.141.141.108 56571 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999
[1778160121.941] [164971:164973] [CAM] Applying candidate: candidate:1 1 udp 1694498815 122.174.39.67 56572 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999
[1778160121.941] [164971:164973] [DMG] Command handler moving to [NewRespons]
[1778160121.941] [164971:164973] [DMG] Command handler moving to [ Preparing]
[1778160121.941] [164971:164973] [DMG] Command handler moving to [AddingComm]
[1778160121.941] [164971:164973] [DMG] Command handler moving to [AddedComma]
[1778160121.941] [164971:164973] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 1
[1778160121.941] [164971:164973] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 0
[1778160121.941] [164971:164973] [DMG] Command handler moving to [AwaitingDe]
[1778160121.941] [164971:164973] [EM] <<< [E:35976r S:10844 M:171433503] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [8697] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:09 (IM:InvokeCommandResponse) (B:64)
[1778160121.941] [164971:164973] [DMG] Command response sender moving to [AllInvokeR]
[1778160141.729] [164971:164998] [CAM] [PeerConnection Gathering State: Complete]

Log from ESP32-C6

ESP32-C6.log

Log from ESP32-P4

ESP32-P4.log

[sayondeep]

@svn-matterize

From the esp32-p4 logs

I (141420) media_stream: I2C initialized successfully
E (141422) sccb_i2c: s_sccb_i2c_transmit_receive_reg_a16v8(128): faled to transmit receive
E (141433) sc2336: Get sensor ID failed
E (141433) esp_video_init: failed to detect MIPI-CSI camera sensor with address=30
E (141444) esp_video_if: Failed to open camera device /dev/video0, errno: 2
E (141445) esp_video_if: Failed to initialize capture video
E (141455) esp32p4_frame_grabber: Failed to initialize video interface
E (141456) esp32p4_frame_grabber: ESP32P4 frame grabber initialization failed
E (141467) esp32p4_frame_grabber: ESP32P4 frame grabber not initialized
E (141467) video_capture_adapter: Failed to start H264 encoder: 259
W (141478) kvs_media: Failed to start video capture streaming: 0x103 (non-fatal, continuing without video)
W (141489) kvs_media: Video capture provided but initialization failed - skipping video transmission

Possible reasons:

1. Hardware issue
2. Unsupported camera module
3. The camera module set in the config option of streaming only example is incorrect.

P.S. You may be using OV5647 camera module. Please set the config option in streaming only example accordingly.

[svn-matterize]

@sayondeep
As you pointed out earlier, the previous issue related to camera sensor initialization appears to be resolved now.

I reconfigured the setup to use the OV5647 sensor at 1920x1080 resolution, and the ESP32-P4 side now detects and initializes the camera successfully:
However, video streaming is still not happening

in ESP32P4

I (449872) message_utils: Creating buffer of capacity 1012
I (449872) message_utils: Appending message of size 1012 at 0 location, is_fin: 1
I (449873) app_webrtc: Using pre-initialized peer connection client
I (449884) app_webrtc: Progressive ICE not supported for new session - using default STUN + async update strategy
I (449895) app_webrtc: Setting default STUN server immediately: stun:stun.l.google.com:19302
I (449906) kvs_webrtc: Updating ICE servers for KVS peer connection client (new count: 1)
I (449907) kvs_webrtc: ICE Server 0: stun:stun.l.google.com:19302
I (449918) kvs_webrtc: Updated ICE server configuration: 1 servers
I (449918) kvs_webrtc: Progressive ICE: No existing sessions to update - new ICE servers will be used for future connections
I (449930) app_webrtc: Default STUN server set - ICE gathering can start immediately
I (449941) bridge_signaling: Triggering background bridge ICE configuration via work queue
I (449952) app_webrtc: Traditional ICE refresh triggered successfully for new session
I (449953) kvs_webrtc: Creating KVS peer connection for peer: 0x00000000
I (449964) kvs_webrtc: ICE server 0: stun:stun.l.google.com:19302
I (449964) kvs_webrtc: Using pre-generated certificate (remaining in pool: 2)
I (449975) kvs_webrtc: Using certificate for peer connection
I (449998) kvs_webrtc: KVS peer connection created successfully
I (449999) kvs_webrtc: Setting up media tracks for peer: 0x00000000
I (450003) kvs_webrtc: Media tracks configured successfully
I (450004) kvs_webrtc: Added session 0x00000000 to internal metrics tracking (hash=0x6528d9e9)
I (450016) kvs_webrtc: Session creation: Session count 0 -> 1 (peer: 0x00000000)
I (450027) kvs_webrtc: Starting global media threads for first session: 0x00000000
W (450028) i2c.master: Please check pull-up resistances whether be connected properly. Otherwise unexpected behavior would happen. For more detailed information, please read docs
I (450050) media_stream: I2C initialized successfully
I (450052) ov5647: Detected Camera sensor PID=0x5647
I (450081) esp_video_if: version: 1.4.1
I (450082) esp_video_if: driver:  MIPI-CSI
I (450082) esp_video_if: card:    MIPI-CSI
I (450083) esp_video_if: bus:     esp32p4:MIPI-CSI
I (450093) esp_video_if: capabilities:
I (450094) esp_video_if: 	VIDEO_CAPTURE
I (450094) esp_video_if: 	STREAMING
I (450105) esp_video_if: device capabilities:
I (450105) esp_video_if: 	VIDEO_CAPTURE
I (450105) esp_video_if: 	STREAMING
I (450116) esp_video_if: Default: width=1920 height=1080
I (450116) esp_video_if: Camera capture initialized and streaming started
I (450127) esp_video_if: Attempting to set format: 1920x1080
I (450128) esp_video_if: Successfully set format: 1920x1080
I (450151) esp32p4_frame_grabber: Configuring encoder with actual camera resolution: 1920x1080@30
I (450151) H264 HW: Func:esp_h264_setup_encoder, Line:216, MEM Total:24010964 Bytes, SPI:23605800 Bytes, SPI:23605800 Bytes

I (450236) kvs_media: Video frame rate control: 30 fps (frame interval: 33333 us)
I (450236) kvs_media: Global video sender thread started
W (450238) i2s_common: dma frame num is adjusted to 256 to align the dma buffer with 64, bufsize = 512
W (450250) i2s_common: dma frame num is adjusted to 256 to align the dma buffer with 64, bufsize = 512
I (450269) ES8311: Work in Slave mode
I (450272) I2S_IF: Paired data: 0x4ff77204, current mode: record, paired in_enable: 0, paired out_enable: 0
W (450273) i2s_common: dma frame num is adjusted to 256 to align the dma buffer with 64, bufsize = 512
I (450284) I2S_IF: STD: RX, data_bit: 16, slot_bit: 16, ws_width: 16, slot_mode: MONO, slot_mask: 0x1
I (450295) I2S_IF: STD: RX, sample_rate_hz: 16000, mclk_multiple: 256, clk_src: 0
W (450296) i2s_common: dma frame num is adjusted to 256 to align the dma buffer with 64, bufsize = 512
I (450307) I2S_IF: STD: TX, data_bit: 16, slot_bit: 16, ws_width: 16, slot_mode: MONO, slot_mask: 0x1
I (450318) I2S_IF: STD: TX, sample_rate_hz: 16000, mclk_multiple: 256, clk_src: 0
I (450344) Adev_Codec: Open codec device OK
I (450444) OpusFrameGrabber: The available total size of heap:17510400
	Description	Internal	SPIRAM
Current Free Memory	207948		17302452
Largest Free Block	163840		16777216
Min. Ever Free Size	207948		17302452
I (450457) kvs_media: Global audio sender thread started
I (450457) kvs_media: Audio frame rate control: 20 ms per frame (frame interval: 20000 us)
I (450457) kvs_webrtc: Global media threads started successfully
I (450479) kvs_webrtc: Created KVS peer connection session for peer: 0x00000000 (initiator: false)
I (450480) kvs_webrtc: kvs_pc_set_callbacks: Setting callbacks for peer 0x00000000
I (450491) kvs_webrtc:   - custom_data: 0x48f79874
I (450492) kvs_webrtc:   - on_message_received: 0x4003f30c
I (450503) kvs_webrtc:   - on_peer_state_changed: 0x4003f3e6
I (450503) kvs_webrtc: Set KVS peer connection callbacks for peer: 0x00000000 (msg_cb=0x4003f30c)
I (450533) kvs_webrtc: Peer connection state change: peer=0x00000000, KVS_state=2
I (450534) app_webrtc: peerConnectionStateChangedWrapper: peer=0x00000000, state=1
I (450554) bridge_signaling: Sending message via bridge signaling
I (450565) kvs_webrtc: Sending answer to peer: 0x00000000
I (450567) streaming_only: [KVS Event] Sent Answer.
I (450567) bridge_signaling: Sending message via bridge signaling
I (450602) bridge_signaling: Sending message via bridge signaling
I (450697) app_webrtc: peerConnectionStateChangedWrapper: peer=0x00000000, state=5
I (450698) app_webrtc: Media starting for peer 0x00000000 (handled by kvs_webrtc interface)
I (450710) streaming_only: [KVS Event] Streaming Started for Peer: 0x00000000
W (450710) video_player_adapter: video_player_init: Stub implementation, no actual playback will occur
W (450721) video_player_adapter: video_player_start: Stub implementation, no actual playback will occur
I (450740) ES8311: Work in Slave mode
I (451584) message_utils: Creating buffer of capacity 102
I (451585) message_utils: Appending message of size 102 at 0 location, is_fin: 1
I (451619) message_utils: Creating buffer of capacity 96
I (451619) message_utils: Appending message of size 96 at 0 location, is_fin: 1
I (451644) message_utils: Creating buffer of capacity 117
I (451644) message_utils: Appending message of size 117 at 0 location, is_fin: 1
I (451713) kvs_webrtc: Peer connection state change: peer=0x00000000, KVS_state=3
I (451715) OPUS_AUDIO_PLAYER: OPUS audio player initialized
I (451716) app_webrtc: peerConnectionStateChangedWrapper: peer=0x00000000, state=2
I (451727) app_webrtc: Peer connection state for 0x00000000: 2
I (451728) streaming_only: [KVS Event] Peer Connected: 0x00000000
W (451729) i2s_common: dma frame num is adjusted to 256 to align the dma buffer with 64, bufsize = 512
I (451739) streaming_only: Updated data channel context with peer ID: 0x00000000
I (451750) I2S_IF: STD: TX, data_bit: 16, slot_bit: 16, ws_width: 16, slot_mode: MONO, slot_mask: 0x1
I (451762) I2S_IF: STD: TX, sample_rate_hz: 16000, mclk_multiple: 256, clk_src: 0
E (451729) OpusFrameGrabber: esp_codec_dev_read error: ESP_FAIL
W (451773) i2s_common: dma frame num is adjusted to 256 to align the dma buffer with 64, bufsize = 512
I (451785) I2S_IF: STD: RX, data_bit: 16, slot_bit: 16, ws_width: 16, slot_mode: MONO, slot_mask: 0x1
I (451796) I2S_IF: STD: RX, sample_rate_hz: 16000, mclk_multiple: 256, clk_src: 0
I (451823) Adev_Codec: Open codec device OK
I (451824) OPUS_AUDIO_PLAYER: OPUS audio player initialized
I (451835) bridge_signaling: Background bridge ICE refresh task started
I (451835) ice_bridge_client: Requesting ICE servers via synchronous RPC (bypasses event queue!)
I (451846) ice_bridge_client: RPC: Requesting ICE server at index 0 (try 0/10)
E (451874) rpc_rsp: Failure resp/event: possibly precondition not met
I (451875) rpc_wrap: print_cleanup_usr_resp: err_resp[-1] for req[519]
E (451876) ice_bridge_client: RPC request failed: -1
W (451887) ice_bridge_client: No servers received from signaling device - using fallback STUN
I (451898) ice_bridge_client: RPC: Successfully configured 1 ICE servers via synchronous calls!
E (451899) bridge_signaling: Background bridge ICE refresh failed: 0x0000000c
I (454698) stats: STA: s2h{in[78] out[78]} h2s{in(flowctrl_drop[0] in[175 or 175]) out(ok[175] drop[0])} flwctl{on[0] off[0]}
I (459698) stats: STA: s2h{in[127] out[127]} h2s{in(flowctrl_drop[0] in[463 or 463]) out(ok[463] drop[0])} flwctl{on[0] off[0]}
I (464698) stats: STA: s2h{in[175] out[175]} h2s{in(flowctrl_drop[0] in[750 or 750]) out(ok[750] drop[0])} flwctl{on[0] off[0]}
I (469698) stats: STA: s2h{in[227] out[227]} h2s{in(flowctrl_drop[0] in[1041 or 1041]) out(ok[1041] drop[0])} flwctl{on[0] off[0]}
I (470571) kvs_webrtc: ICE candidate gathering finished for peer: 0x00000000
I (474698) stats: STA: s2h{in[277] out[277]} h2s{in(flowctrl_drop[0] in[1329 or 1329]) out(ok[1329] drop[0])} flwctl{on[0] off[0]}
I (479698) stats: STA: s2h{in[327] out[327]} h2s{in(flowctrl_drop[0] in[1617 or 1617]) out(ok[1617] drop[0])} flwctl{on[0] off[0]}
I (484698) stats: STA: s2h{in[378] out[378]} h2s{in(flowctrl_drop[0] in[1908 or 1908]) out(ok[1908] drop[0])} flwctl{on[0] off[0]}
I (489698) stats: STA: s2h{in[430] out[430]} h2s{in(flowctrl_drop[0] in[2198 or 2198]) out(ok[2198] drop[0])} flwctl{on[0] off[0]}
I (494698) stats: STA: s2h{in[478] out[478]} h2s{in(flowctrl_drop[0] in[2484 or 2484]) out(ok[2484] drop[0])} flwctl{on[0] off[0]}
I (499698) stats: STA: s2h{in[534] out[534]} h2s{in(flowctrl_drop[0] in[2780 or 2780]) out(ok[2780] drop[0])} flwctl{on[0] off[0]}
I (504698) stats: STA: s2h{in[588] out[588]} h2s{in(flowctrl_drop[0] in[3072 or 3072]) out(ok[3072] drop[0])} flwctl{on[0] off[0]}
I (509698) stats: STA: s2h{in[639] out[639]} h2s{in(flowctrl_drop[0] in[3361 or 3361]) out(ok[3361] drop[0])} flwctl{on[0] off[0]}
I (514698) stats: STA: s2h{in[690] out[690]} h2s{in(flowctrl_drop[0] in[3651 or 3651]) out(ok[3651] drop[0])} flwctl{on[0] off[0]}
I (519698) stats: STA: s2h{in[736] out[736]} h2s{in(flowctrl_drop[0] in[3936 or 3936]) out(ok[3936] drop[0])} flwctl{on[0] off[0]}
I (524698) stats: STA: s2h{in[785] out[785]} h2s{in(flowctrl_drop[0] in[4224 or 4224]) out(ok[4224] drop[0])} flwctl{on[0] off[0]}
I (529698) stats: STA: s2h{in[842] out[842]} h2s{in(flowctrl_drop[0] in[4520 or 4520]) out(ok[4520] drop[0])} flwctl{on[0] off[0]}
I (534698) stats: STA: s2h{in[894] out[894]} h2s{in(flowctrl_drop[0] in[4810 or 4810]) out(ok[4810] drop[0])} flwctl{on[0] off[0]}
I (539698) stats: STA: s2h{in[948] out[948]} h2s{in(flowctrl_drop[0] in[5103 or 5103]) out(ok[5103] drop[0])} flwctl{on[0] off[0]}
I (544698) stats: STA: s2h{in[997] out[997]} h2s{in(flowctrl_drop[0] in[5391 or 5391]) out(ok[5391] drop[0])} flwctl{on[0] off[0]}

and in Linux host camera controller

most of the times it shows like

[1779451447.581] [60610:60612] [DMG] AccessControl: checking f=1 a=c s=0x0000000000000001 t= c=0x0000_0554 e=1 p=o r=i
[1779451447.581] [60610:60612] [DMG] AccessControl: allowed (delegate)
[1779451447.581] [60610:60612] [DMG] Received command for Endpoint=1 Cluster=0x0000_0554 Command=0x0000_0002
[1779451447.581] [60610:60612] [CAM] WebRTCRequestorDelegate::HandleICECandidates
[1779451447.581] [60610:60612] [CAM] WebRTCManager::HandleICECandidates
[1779451447.581] [60610:60612] [CAM] Applying candidate: candidate:0 1 udp 2130706431 141.141.141.108 51445 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999
[1779451447.581] [60610:60612] [CAM] Applying candidate: candidate:1 1 udp 1694498815 117.96.217.92 51446 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999
[1779451447.582] [60610:60612] [DMG] Command handler moving to [NewRespons]
[1779451447.582] [60610:60612] [DMG] Command handler moving to [ Preparing]
[1779451447.582] [60610:60612] [DMG] Command handler moving to [AddingComm]
[1779451447.582] [60610:60612] [DMG] Command handler moving to [AddedComma]
[1779451447.582] [60610:60612] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 1
[1779451447.582] [60610:60612] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 0
[1779451447.582] [60610:60612] [DMG] Command handler moving to [AwaitingDe]
[1779451447.582] [60610:60612] [EM] <<< [E:3836r S:48936 M:243112082] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:09 (IM:InvokeCommandResponse) (B:64)
[1779451447.582] [60610:60612] [DMG] Command response sender moving to [AllInvokeR]
[1779451447.697] [60610:61072] [CAM] [PeerConnection State: Connected]
[1779451447.697] [60610:61072] [CAM] WebRTC session established for stream ID: 2
[1779451447.697] [60610:61072] [CAM] Starting video stream process for stream ID: 2
[1779451447.697] [60610:61072] [CAM] Stopping video stream process (PID: 61087) for stream ID: 2
[1779451447.702] [60610:61079] [CAM] Video stream process (PID: 61087) terminated
[1779451448.699] [60610:61072] [CAM] Video stream process started with PID: 63015

Click to expand log

liveview start 1 --min-res-width 640 --min-res-height 480 --min-framerate 30
[1779450488.287] [60610:60610] [-] Command: liveview start 1 --min-res-width 640 --min-res-height 480 --min-framerate 30 
[1779450488.287] [60610:60612] [CAM] Run LiveViewStartCommand
[1779450488.287] [60610:60612] [CAM] Allocate a video stream on the camera device.
[1779450488.287] [60610:60612] [CAM] Sending VideoStreamAllocate to (node=0x0000000000000001, ep=1, usage=3)
[1779450488.287] [60610:60612] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1779450488.287] [60610:60612] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1779450488.287] [60610:60612] [DIS] Found an existing secure session to [1:0000000000000001]!
[1779450488.287] [60610:60612] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1779450488.287] [60610:60612] [SVR] Sending command with Endpoint ID: 1, Command Type: 1
[1779450488.287] [60610:60612] [DMG] ICR moving to [AddingComm]
[1779450488.287] [60610:60612] [DMG] ICR moving to [AddedComma]
[1779450488.287] [60610:60612] [EM] <<< [E:26797i S:48933 M:77642868] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:110)
[1779450488.287] [60610:60612] [EM] ??1 [E:26797i S:48933 M:77642868] (S) Msg Retransmission to 1:0000000000000001 scheduled for 559ms from now [State:Idle II:500 AI:300 AT:4000]
[1779450488.287] [60610:60612] [DMG] ICR moving to [AwaitingRe]
[1779450488.446] [60610:60612] [EM] >>> [E:26797i S:48933 M:91608302 (Ack:77642868)] (S) Msg RX from 1:0000000000000001 [7F90] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:68)
[1779450488.446] [60610:60612] [EM] Found matching exchange: 26797i, Delegate: 0x70f198007aa8
[1779450488.446] [60610:60612] [EM] Rxd Ack; Removing MessageCounter:77642868 from Retrans Table on exchange 26797i
[1779450488.446] [60610:60612] [DMG] ICR moving to [ResponseRe]
[1779450488.446] [60610:60612] [DMG] InvokeResponseMessage =
[1779450488.446] [60610:60612] [DMG] {
[1779450488.446] [60610:60612] [DMG] 	suppressResponse = false, 
[1779450488.446] [60610:60612] [DMG] 	InvokeResponseIBs =
[1779450488.447] [60610:60612] [DMG] 	[
[1779450488.447] [60610:60612] [DMG] 		InvokeResponseIB =
[1779450488.447] [60610:60612] [DMG] 		{
[1779450488.447] [60610:60612] [DMG] 			CommandDataIB =
[1779450488.447] [60610:60612] [DMG] 			{
[1779450488.447] [60610:60612] [DMG] 				CommandPathIB =
[1779450488.447] [60610:60612] [DMG] 				{
[1779450488.447] [60610:60612] [DMG] 					EndpointId = 0x1,
[1779450488.447] [60610:60612] [DMG] 					ClusterId = 0x551,
[1779450488.447] [60610:60612] [DMG] 					CommandId = 0x4,
[1779450488.447] [60610:60612] [DMG] 				},
[1779450488.447] [60610:60612] [DMG] 				
[1779450488.447] [60610:60612] [DMG] 				CommandFields = 
[1779450488.447] [60610:60612] [DMG] 				{
[1779450488.447] [60610:60612] [DMG] 					0x0 = 2 (unsigned), 
[1779450488.447] [60610:60612] [DMG] 				},
[1779450488.447] [60610:60612] [DMG] 			},
[1779450488.447] [60610:60612] [DMG] 			
[1779450488.447] [60610:60612] [DMG] 		},
[1779450488.447] [60610:60612] [DMG] 		
[1779450488.447] [60610:60612] [DMG] 	],
[1779450488.447] [60610:60612] [DMG] 	
[1779450488.447] [60610:60612] [DMG] 	InteractionModelRevision = 12
[1779450488.447] [60610:60612] [DMG] },
[1779450488.447] [60610:60612] [DMG] Received Command Response Data, Endpoint=1 Cluster=0x0000_0551 Command=0x0000_0004
[1779450488.447] [60610:60612] [CAM] AVStreamManagement: OnResponse.
[1779450488.447] [60610:60612] [CAM] Command Response received.
[1779450488.447] [60610:60612] [CAM] Handle VideoStreamAllocateResponse command.
[1779450488.447] [60610:60612] [CAM] DecodableType fields:
[1779450488.447] [60610:60612] [CAM]   videoStreamId: 2
[1779450488.447] [60610:60612] [CAM] DeviceManager: Initiating WebRTC session for node=0x0000000000000001
[1779450488.447] [60610:60612] [CAM] Attempting to establish WebRTC connection to node 0x0000000000000001 on endpoint 0x1
[1779450488.447] [60610:60612] [CAM] Disconnecting WebRTC session
[1779450488.447] [60610:60612] [CAM] Commissioner is on Fabric ID 0x0000000000000001
[1779450488.447] [60610:60612] [CAM] WebRTCProviderClient: Initialized with PeerId=0x0000000000000001, endpoint=1
[1779450488.450] [60610:60612] [CAM] Generate and set the SDP
[1779450488.451] [60610:61064] [CAM] Local Description:
[1779450488.451] [60610:61064] [CAM] v=0
o=rtc 1872026961 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE video audio
a=group:LS video audio
a=msid-semantic:WMS *
a=ice-options:ice2,trickle
a=fingerprint:sha-256 EC:7E:0D:42:06:56:A4:9D:A6:5D:05:11:14:5C:59:FD:CF:A7:1B:FC:71:15:CB:31:80:65:70:1C:B9:6B:E0:04
m=video 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
b=AS:3000
a=mid:video
a=recvonly
a=rtcp-mux
a=rtpmap:96 H264/90000
a=rtcp-fb:96 nack
a=rtcp-fb:96 nack pli
a=rtcp-fb:96 goog-remb
a=fmtp:96 profile-level-id=42e01f;packetization-mode=1;level-asymmetry-allowed=1
a=setup:actpass
a=ice-ufrag:lqB/
a=ice-pwd:HnqCEIv1PKBZN2j7B0sJKD
m=audio 9 UDP/TLS/RTP/SAVPF 111
c=IN IP4 0.0.0.0
b=AS:64000
a=mid:audio
a=recvonly
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10;maxaveragebitrate=96000;stereo=1;sprop-stereo=1;useinbandfec=1
a=setup:actpass
a=ice-ufrag:lqB/
a=ice-pwd:HnqCEIv1PKBZN2j7B0sJKD

[1779450488.451] [60610:61064] [CAM] Extracted 0 candidates from SDP description
[1779450488.451] [60610:61064] [CAM] [PeerConnection Gathering State: InProgress]
[1779450488.451] [60610:61068] [CAM] Local Candidate:
[1779450488.451] [60610:61068] [CAM] a=candidate:2 1 UDP 2116026111 fd00:141:141:141::885 35035 typ host
[1779450488.451] [60610:61068] [CAM]   mid: video, mlineIndex: -1
[1779450488.451] [60610:61068] [CAM] Local Candidate:
[1779450488.451] [60610:61068] [CAM] a=candidate:1 1 UDP 2114977791 141.141.141.107 35035 typ host
[1779450488.451] [60610:61068] [CAM]   mid: video, mlineIndex: -1
[1779450488.451] [60610:61069] [CAM] [PeerConnection State: Connecting]
[1779450488.500] [60610:61072] [CAM] Local Candidate:
[1779450488.500] [60610:61072] [CAM] a=candidate:3 1 UDP 1678769663 117.96.217.92 35035 typ srflx raddr 0.0.0.0 rport 0
[1779450488.500] [60610:61072] [CAM]   mid: video, mlineIndex: -1
[1779450489.452] [60610:60612] [CAM] Using ProvideOffer for WebRTC session establishment
[1779450489.452] [60610:60612] [CAM] Sending ProvideOffer command to the peer device
[1779450489.452] [60610:60612] [CAM] Tracking stream ID 2 for WebRTC session
[1779450489.452] [60610:60612] [CAM] Sending ProvideOffer to node 0000000000000001
[1779450489.452] [60610:60612] [CAM] WebRTCProviderClient moving to [ Connecting ]
[1779450489.452] [60610:60612] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1779450489.452] [60610:60612] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1779450489.452] [60610:60612] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1779450489.452] [60610:60612] [DIS] Lookup started for 0F3AC7E7BCDC7F90-0000000000000001
[1779450489.452] [60610:60612] [DMG] ICR moving to [AwaitingDe]
[1779450489.452] [60610:60612] [CAM] AVStreamManagement: OnDone.
[1779450489.452] [60610:60612] [CAM] AVStreamManagement: Command VideoStreamAllocate has been successfully processed.
[1779450489.452] [60610:60612] [EM] <<< [E:26797i S:48933 M:77642869 (Ack:91608302)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1779450489.452] [60610:60612] [EM] Flushed pending ack for MessageCounter:91608302 on exchange 26797i
[1779450489.452] [60610:60612] [IN] Received a duplicate message with MessageCounter:91608302 on exchange 26797i
[1779450489.452] [60610:60612] [EM] >>> [E:26797i S:48933 M:91608302 (Ack:77642868)] (S) Msg RX from 1:0000000000000001 [7F90] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:68)
[1779450489.452] [60610:60612] [EM] Generating StandaloneAck via exchange: 26797i
[1779450489.452] [60610:60612] [EM] Forcing tx of solitary ack for duplicate MessageCounter:91608302 on exchange 26797i
[1779450489.453] [60610:60612] [EM] <<< [E:26797i S:48933 M:77642870 (Ack:91608302)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1779450489.453] [60610:60612] [IN] Received a duplicate message with MessageCounter:91608302 on exchange 26797i
[1779450489.453] [60610:60612] [EM] >>> [E:26797i S:48933 M:91608302 (Ack:77642868)] (S) Msg RX from 1:0000000000000001 [7F90] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:68)
[1779450489.453] [60610:60612] [EM] Generating StandaloneAck via exchange: 26797i
[1779450489.453] [60610:60612] [EM] Forcing tx of solitary ack for duplicate MessageCounter:91608302 on exchange 26797i
[1779450489.453] [60610:60612] [EM] <<< [E:26797i S:48933 M:77642871 (Ack:91608302)] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1779450489.614] [60610:60612] [DIS] UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540: new best score: 7 (for 0F3AC7E7BCDC7F90-0000000000000001)
[1779450489.615] [60610:60612] [DIS] Lookup clearing interface for non LL address
[1779450489.615] [60610:60612] [DIS] UDP:[fd00:141:141:141:e6b3:23ff:fe90:8844%wlp3s0]:5540: new best score: 5 (for 0F3AC7E7BCDC7F90-0000000000000001)
[1779450489.615] [60610:60612] [DIS] Lookup clearing interface for non LL address
[1779450489.615] [60610:60612] [DIS] UDP:141.141.141.108%wlp3s0:5540: new best score: 2 (for 0F3AC7E7BCDC7F90-0000000000000001)
[1779450489.615] [60610:60612] [DIS] Checking node lookup status for 0F3AC7E7BCDC7F90-0000000000000001 after 163 ms
[1779450489.615] [60610:60612] [DIS] Keeping DNSSD lookup active
[1779450489.652] [60610:60612] [DIS] Checking node lookup status for 0F3AC7E7BCDC7F90-0000000000000001 after 200 ms
[1779450489.652] [60610:60612] [DIS] OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540 while in state 2
[1779450489.652] [60610:60612] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1779450489.652] [60610:60612] [IN] SecureSession[0x70f19803e680]: Allocated Type:2 LSID:48934
[1779450489.652] [60610:60612] [SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1779450489.652] [60610:60612] [IN] Connecting over TCP with peer at TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540.
[1779450489.652] [60610:60612] [IN] Connecting to peer TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540.
[1779450489.653] [60610:60612] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1779450489.657] [60610:60612] [IN] Connection established successfully with TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540.
[1779450489.657] [60610:60612] [SC] TCP Connection established with TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540 before session establishment
[1779450489.657] [60610:60612] [EM] <<< [E:26798i S:0 M:37377960] (U) Msg TX from DBBC5D6EC8F15EF6 to 0:0000000000000000 [0000] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:234)
[1779450489.657] [60610:60612] [SC] Sent Sigma1 msg to <0000000000000001, 1> [II:500ms AI:300ms AT:4000ms]
[1779450489.715] [60610:60612] [EM] >>> [E:26798i S:0 M:175383282] (U) Msg RX from 0:0000000000000000 [0000] to DBBC5D6EC8F15EF6 --- Type 0000:33 (SecureChannel:CASE_Sigma2Resume) (B:96)
[1779450489.715] [60610:60612] [EM] Found matching exchange: 26798i, Delegate: 0x70f1980265b8
[1779450489.715] [60610:60612] [SC] Received Sigma2Resume msg
[1779450489.715] [60610:60612] [SC] Found MRP parameters in the message
[1779450489.716] [60610:60612] [SC] Peer <0000000000000001, 1> assigned session ID 7927
[1779450489.717] [60610:60612] [SC] Sending status report. Protocol code 0, exchange 26798
[1779450489.717] [60610:60612] [EM] <<< [E:26798i S:0 M:37377961] (U) Msg TX from DBBC5D6EC8F15EF6 to 0:0000000000000000 [0000] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
[1779450489.717] [60610:60612] [SC] SecureSession[0x70f19803e680, LSID:48934]: State change 'kEstablishing' --> 'kActive'
[1779450489.717] [60610:60612] [IN] SecureSession[0x70f19803e680]: Activated - Type:2 LSID:48934
[1779450489.717] [60610:60612] [IN] New secure session activated for device <0000000000000001, 1>, LSID:48934 PSID:7927!
[1779450489.717] [60610:60612] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1779450489.717] [60610:60612] [CAM] CASE session established, sending WebRTCTransportProvider command...
[1779450489.717] [60610:60612] [CAM] Sending command with Endpoint ID: 1, Command Type: 2
[1779450489.717] [60610:60612] [DMG] ICR moving to [AddingComm]
[1779450489.717] [60610:60612] [DMG] ICR moving to [AddedComma]
[1779450489.717] [60610:60612] [EM] <<< [E:26799i S:48934 M:254856867] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:973)
[1779450489.717] [60610:60612] [DMG] ICR moving to [AwaitingRe]
[1779450489.717] [60610:60612] [CAM] WebRTCProviderClient moving to [ AwaitingResponse ]
[1779450489.915] [60610:60612] [EM] >>> [E:26799i S:48934 M:115865885] (S) Msg RX from 1:0000000000000001 [7F90] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:67)
[1779450489.915] [60610:60612] [EM] Found matching exchange: 26799i, Delegate: 0x70f198007aa8
[1779450489.915] [60610:60612] [DMG] ICR moving to [ResponseRe]
[1779450489.915] [60610:60612] [DMG] InvokeResponseMessage =
[1779450489.915] [60610:60612] [DMG] {
[1779450489.915] [60610:60612] [DMG] 	suppressResponse = false, 
[1779450489.915] [60610:60612] [DMG] 	InvokeResponseIBs =
[1779450489.915] [60610:60612] [DMG] 	[
[1779450489.915] [60610:60612] [DMG] 		InvokeResponseIB =
[1779450489.915] [60610:60612] [DMG] 		{
[1779450489.915] [60610:60612] [DMG] 			CommandDataIB =
[1779450489.915] [60610:60612] [DMG] 			{
[1779450489.915] [60610:60612] [DMG] 				CommandPathIB =
[1779450489.915] [60610:60612] [DMG] 				{
[1779450489.915] [60610:60612] [DMG] 					EndpointId = 0x1,
[1779450489.915] [60610:60612] [DMG] 					ClusterId = 0x553,
[1779450489.915] [60610:60612] [DMG] 					CommandId = 0x3,
[1779450489.916] [60610:60612] [DMG] 				},
[1779450489.916] [60610:60612] [DMG] 				
[1779450489.916] [60610:60612] [DMG] 				CommandFields = 
[1779450489.916] [60610:60612] [DMG] 				{
[1779450489.916] [60610:60612] [DMG] 					0x0 = 0 (unsigned), 
[1779450489.916] [60610:60612] [DMG] 					0x1 = 2 (unsigned), 
[1779450489.916] [60610:60612] [DMG] 				},
[1779450489.916] [60610:60612] [DMG] 			},
[1779450489.916] [60610:60612] [DMG] 			
[1779450489.916] [60610:60612] [DMG] 		},
[1779450489.916] [60610:60612] [DMG] 		
[1779450489.916] [60610:60612] [DMG] 	],
[1779450489.916] [60610:60612] [DMG] 	
[1779450489.916] [60610:60612] [DMG] 	InteractionModelRevision = 12
[1779450489.916] [60610:60612] [DMG] },
[1779450489.916] [60610:60612] [DMG] Received Command Response Data, Endpoint=1 Cluster=0x0000_0553 Command=0x0000_0003
[1779450489.916] [60610:60612] [CAM] WebRTCProviderClient: OnResponse received for cluster: 0x553 command: 0x3
[1779450489.916] [60610:60612] [CAM] Processing ProvideOfferResponse
[1779450489.916] [60610:60612] [CAM] WebRTCProviderClient::HandleProvideOfferResponse.
[1779450489.916] [60610:60612] [CAM] WebRTCProviderClient moving to [ AwaitingAnswer ]
[1779450489.916] [60610:60612] [DMG] ICR moving to [AwaitingDe]
[1779450489.916] [60610:60612] [CAM] WebRTCProviderClient: OnDone for command 2.
[1779450491.226] [60610:60612] [EM] >>> [E:64068r S:48934 M:115865886] (S) Msg RX from 1:0000000000000001 [7F90] to 000000000001B669 --- Type 0001:08 (IM:InvokeCommandRequest) (B:2034)
[1779450491.226] [60610:60612] [EM] Handling via exchange: 64068r, Delegate: 0x59fe6a41bf68
[1779450491.226] [60610:60612] [DMG] InvokeRequestMessage =
[1779450491.226] [60610:60612] [DMG] {
[1779450491.226] [60610:60612] [DMG] 	suppressResponse = false, 
[1779450491.226] [60610:60612] [DMG] 	timedRequest = false, 
[1779450491.226] [60610:60612] [DMG] 	InvokeRequests =
[1779450491.226] [60610:60612] [DMG] 	[
[1779450491.226] [60610:60612] [DMG] 		CommandDataIB =
[1779450491.226] [60610:60612] [DMG] 		{
[1779450491.226] [60610:60612] [DMG] 			CommandPathIB =
[1779450491.226] [60610:60612] [DMG] 			{
[1779450491.226] [60610:60612] [DMG] 				EndpointId = 0x1,
[1779450491.226] [60610:60612] [DMG] 				ClusterId = 0x554,
[1779450491.226] [60610:60612] [DMG] 				CommandId = 0x1,
[1779450491.226] [60610:60612] [DMG] 			},
[1779450491.226] [60610:60612] [DMG] 			
[1779450491.226] [60610:60612] [DMG] 			CommandFields = 
[1779450491.226] [60610:60612] [DMG] 			{
[1779450491.226] [60610:60612] [DMG] 				0x0 = 0 (unsigned), 
[1779450491.226] [60610:60612] [DMG] 				0x1 = ... (char string too long: 1967 chars) ...
[1779450491.226] [60610:60612] [DMG] 			},
[1779450491.226] [60610:60612] [DMG] 		},
[1779450491.226] [60610:60612] [DMG] 		
[1779450491.227] [60610:60612] [DMG] 	],
[1779450491.227] [60610:60612] [DMG] 	
[1779450491.227] [60610:60612] [DMG] 	InteractionModelRevision = 12
[1779450491.227] [60610:60612] [DMG] },
[1779450491.227] [60610:60612] [DMG] AccessControl: checking f=1 a=c s=0x0000000000000001 t= c=0x0000_0554 e=1 p=o r=i
[1779450491.227] [60610:60612] [DMG] AccessControl: allowed (delegate)
[1779450491.227] [60610:60612] [DMG] Received command for Endpoint=1 Cluster=0x0000_0554 Command=0x0000_0001
[1779450491.227] [60610:60612] [CAM] WebRTCRequestorDelegate::HandleAnswer
[1779450491.227] [60610:60612] [CAM] WebRTCManager::HandleAnswer
[1779450491.227] [60610:60612] [CAM] Answer command received for WebRTC session ID: 0
[1779450491.227] [60610:60612] [CAM] WebRTCProviderClient moving to [ Idle ]
[1779450491.227] [60610:60612] [DMG] Command handler moving to [NewRespons]
[1779450491.227] [60610:60612] [DMG] Command handler moving to [ Preparing]
[1779450491.227] [60610:60612] [DMG] Command handler moving to [AddingComm]
[1779450491.227] [60610:60612] [DMG] Command handler moving to [AddedComma]
[1779450491.227] [60610:60612] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 1
[1779450491.227] [60610:60612] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 0
[1779450491.227] [60610:60612] [DMG] Command handler moving to [AwaitingDe]
[1779450491.227] [60610:60612] [EM] <<< [E:64068r S:48934 M:254856868] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:09 (IM:InvokeCommandResponse) (B:64)
[1779450491.227] [60610:60612] [DMG] Command response sender moving to [AllInvokeR]
[1779450491.528] [60610:60612] [CAM] Sending ProvideICECandidates command to the peer device
[1779450491.528] [60610:60612] [CAM] Sending ProvideICECandidates to node 0000000000000001
[1779450491.528] [60610:60612] [CAM] WebRTCProviderClient moving to [ Connecting ]
[1779450491.528] [60610:60612] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1779450491.528] [60610:60612] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1779450491.528] [60610:60612] [DIS] Found an existing secure session to [1:0000000000000001]!
[1779450491.528] [60610:60612] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1779450491.528] [60610:60612] [CAM] CASE session established, sending WebRTCTransportProvider command...
[1779450491.528] [60610:60612] [CAM] Sending command with Endpoint ID: 1, Command Type: 4
[1779450491.528] [60610:60612] [DMG] ICR moving to [AddingComm]
[1779450491.528] [60610:60612] [DMG] ICR moving to [AddedComma]
[1779450491.528] [60610:60612] [EM] <<< [E:26800i S:48934 M:254856869] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:321)
[1779450491.528] [60610:60612] [DMG] ICR moving to [AwaitingRe]
[1779450491.528] [60610:60612] [CAM] WebRTCProviderClient moving to [ AwaitingResponse ]
[1779450491.528] [60610:60612] [CAM] Sent 3 ICE candidate(s)
[1779450491.528] [60610:60612] [CAM] Sent 3 ICE candidate(s), clearing list
[1779450491.696] [60610:60612] [EM] >>> [E:26800i S:48934 M:115865887] (S) Msg RX from 1:0000000000000001 [7F90] to 000000000001B669 --- Type 0001:09 (IM:InvokeCommandResponse) (B:64)
[1779450491.696] [60610:60612] [EM] Found matching exchange: 26800i, Delegate: 0x70f198007aa8
[1779450491.696] [60610:60612] [DMG] ICR moving to [ResponseRe]
[1779450491.696] [60610:60612] [DMG] InvokeResponseMessage =
[1779450491.696] [60610:60612] [DMG] {
[1779450491.696] [60610:60612] [DMG] 	suppressResponse = false, 
[1779450491.696] [60610:60612] [DMG] 	InvokeResponseIBs =
[1779450491.696] [60610:60612] [DMG] 	[
[1779450491.696] [60610:60612] [DMG] 		InvokeResponseIB =
[1779450491.696] [60610:60612] [DMG] 		{
[1779450491.696] [60610:60612] [DMG] 			CommandStatusIB =
[1779450491.696] [60610:60612] [DMG] 			{
[1779450491.696] [60610:60612] [DMG] 				CommandPathIB =
[1779450491.696] [60610:60612] [DMG] 				{
[1779450491.696] [60610:60612] [DMG] 					EndpointId = 0x1,
[1779450491.696] [60610:60612] [DMG] 					ClusterId = 0x553,
[1779450491.696] [60610:60612] [DMG] 					CommandId = 0x5,
[1779450491.696] [60610:60612] [DMG] 				},
[1779450491.696] [60610:60612] [DMG] 				
[1779450491.696] [60610:60612] [DMG] 				StatusIB =
[1779450491.696] [60610:60612] [DMG] 				{
[1779450491.696] [60610:60612] [DMG] 					status = 0x00 (SUCCESS),
[1779450491.696] [60610:60612] [DMG] 				},
[1779450491.696] [60610:60612] [DMG] 				
[1779450491.696] [60610:60612] [DMG] 			},
[1779450491.696] [60610:60612] [DMG] 			
[1779450491.696] [60610:60612] [DMG] 		},
[1779450491.696] [60610:60612] [DMG] 		
[1779450491.696] [60610:60612] [DMG] 	],
[1779450491.696] [60610:60612] [DMG] 	
[1779450491.696] [60610:60612] [DMG] 	InteractionModelRevision = 12
[1779450491.696] [60610:60612] [DMG] },
[1779450491.697] [60610:60612] [DMG] Received Command Response Status for Endpoint=1 Cluster=0x0000_0553 Command=0x0000_0005 Status=0x0
[1779450491.697] [60610:60612] [CAM] WebRTCProviderClient: OnResponse received for cluster: 0x553 command: 0x5
[1779450491.697] [60610:60612] [CAM] Unexpected command ID: 0x5
[1779450491.697] [60610:60612] [DMG] ICR moving to [AwaitingDe]
[1779450491.697] [60610:60612] [CAM] WebRTCProviderClient: OnDone for command 4.
[1779450491.697] [60610:60612] [CAM] WebRTCProviderClient moving to [ Idle ]
[1779450491.721] [60610:61079] [CAM] [PeerConnection State: Connected]
[1779450491.721] [60610:61079] [CAM] WebRTC session established for stream ID: 2
[1779450491.721] [60610:61079] [CAM] Starting video stream process for stream ID: 2
[1779450491.723] [60610:61079] [CAM] Video stream process started with PID: 61087
[1779450491.737] [60610:60612] [EM] >>> [E:64069r S:48934 M:115865888] (S) Msg RX from 1:0000000000000001 [7F90] to 000000000001B669 --- Type 0001:08 (IM:InvokeCommandRequest) (B:305)
[1779450491.737] [60610:60612] [EM] Handling via exchange: 64069r, Delegate: 0x59fe6a41bf68
[1779450491.737] [60610:60612] [DMG] InvokeRequestMessage =
[1779450491.737] [60610:60612] [DMG] {
[1779450491.737] [60610:60612] [DMG] 	suppressResponse = false, 
[1779450491.737] [60610:60612] [DMG] 	timedRequest = false, 
[1779450491.737] [60610:60612] [DMG] 	InvokeRequests =
[1779450491.737] [60610:60612] [DMG] 	[
[1779450491.737] [60610:60612] [DMG] 		CommandDataIB =
[1779450491.737] [60610:60612] [DMG] 		{
[1779450491.737] [60610:60612] [DMG] 			CommandPathIB =
[1779450491.737] [60610:60612] [DMG] 			{
[1779450491.737] [60610:60612] [DMG] 				EndpointId = 0x1,
[1779450491.737] [60610:60612] [DMG] 				ClusterId = 0x554,
[1779450491.737] [60610:60612] [DMG] 				CommandId = 0x2,
[1779450491.737] [60610:60612] [DMG] 			},
[1779450491.737] [60610:60612] [DMG] 			
[1779450491.737] [60610:60612] [DMG] 			CommandFields = 
[1779450491.737] [60610:60612] [DMG] 			{
[1779450491.737] [60610:60612] [DMG] 				0x0 = 0 (unsigned), 
[1779450491.737] [60610:60612] [DMG] 				0x1 = [
[1779450491.737] [60610:60612] [DMG] 						
[1779450491.737] [60610:60612] [DMG] 					{
[1779450491.737] [60610:60612] [DMG] 						0x0 = "candidate:0 1 udp 2130706431 141.141.141.108 60197 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999" (111 chars), 
[1779450491.737] [60610:60612] [DMG] 						0x1 = NULL
[1779450491.737] [60610:60612] [DMG] 						0x2 = NULL
[1779450491.737] [60610:60612] [DMG] 					},
[1779450491.737] [60610:60612] [DMG] 					{
[1779450491.737] [60610:60612] [DMG] 						0x0 = "candidate:1 1 udp 1694498815 117.96.217.92 60198 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999" (110 chars), 
[1779450491.737] [60610:60612] [DMG] 						0x1 = NULL
[1779450491.737] [60610:60612] [DMG] 						0x2 = NULL
[1779450491.737] [60610:60612] [DMG] 					},
[1779450491.737] [60610:60612] [DMG] 				],
[1779450491.737] [60610:60612] [DMG] 			},
[1779450491.737] [60610:60612] [DMG] 		},
[1779450491.737] [60610:60612] [DMG] 		
[1779450491.737] [60610:60612] [DMG] 	],
[1779450491.737] [60610:60612] [DMG] 	
[1779450491.737] [60610:60612] [DMG] 	InteractionModelRevision = 12
[1779450491.737] [60610:60612] [DMG] },
[1779450491.737] [60610:60612] [DMG] AccessControl: checking f=1 a=c s=0x0000000000000001 t= c=0x0000_0554 e=1 p=o r=i
[1779450491.737] [60610:60612] [DMG] AccessControl: allowed (delegate)
[1779450491.737] [60610:60612] [DMG] Received command for Endpoint=1 Cluster=0x0000_0554 Command=0x0000_0002
[1779450491.737] [60610:60612] [CAM] WebRTCRequestorDelegate::HandleICECandidates
[1779450491.737] [60610:60612] [CAM] WebRTCManager::HandleICECandidates
[1779450491.737] [60610:60612] [CAM] Applying candidate: candidate:0 1 udp 2130706431 141.141.141.108 60197 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999
[1779450491.737] [60610:60612] [CAM] Applying candidate: candidate:1 1 udp 1694498815 117.96.217.92 60198 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999
[1779450491.738] [60610:60612] [DMG] Command handler moving to [NewRespons]
[1779450491.738] [60610:60612] [DMG] Command handler moving to [ Preparing]
[1779450491.738] [60610:60612] [DMG] Command handler moving to [AddingComm]
[1779450491.738] [60610:60612] [DMG] Command handler moving to [AddedComma]
[1779450491.738] [60610:60612] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 1
[1779450491.738] [60610:60612] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 0
[1779450491.738] [60610:60612] [DMG] Command handler moving to [AwaitingDe]
[1779450491.738] [60610:60612] [EM] <<< [E:64069r S:48934 M:254856870] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [7F90] [TCP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:09 (IM:InvokeCommandResponse) (B:64)
[1779450491.738] [60610:60612] [DMG] Command response sender moving to [AllInvokeR]
[1779450512.036] [60610:61077] [CAM] [PeerConnection Gathering State: Complete]

[svn-matterize]

@sayondeep , @dhrishi, @chshu
I tested the updated matter-camera example on an ESP32-C6 using the latest commits (commit 1ae1a91e34fd4ae05c8176824b1dbd8e802aa36e).

Pairing completes smoothly, but running liveview start results in a total timeout.

Specifically, the ESP32-C6 logs throw a serialization error right after receiving the command:

E (189012) chip[DMG]: Failed to finalize command response: 3
E (189023) chip[DMG]: Failed to send InvokeResponseMessage

Because the device fails to construct the outbound response buffer, the ./camera-controller side inevitably triggers a CHIP Error 0x00000032: Timeout. Could this be a heap memory constraint on the C6 or a structure regression introduced in this commit's cluster definitions?

>>> liveview start 1 --min-res-width 640 --min-res-height 480 --min-framerate 30
[1779542751.769] [27464:27464] [-] Command: liveview start 1 --min-res-width 640 --min-res-height 480 --min-framerate 30 
[1779542751.770] [27464:27466] [CAM] Run LiveViewStartCommand
[1779542751.770] [27464:27466] [CAM] Allocate a video stream on the camera device.
[1779542751.770] [27464:27466] [CAM] Sending VideoStreamAllocate to (node=0x0000000000000001, ep=1, usage=3)
[1779542751.770] [27464:27466] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001]
[1779542751.770] [27464:27466] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1779542751.770] [27464:27466] [DIS] Found an existing secure session to [1:0000000000000001]!
[1779542751.770] [27464:27466] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1779542751.770] [27464:27466] [SVR] Sending command with Endpoint ID: 1, Command Type: 1
[1779542751.770] [27464:27466] [DMG] ICR moving to [AddingComm]
[1779542751.770] [27464:27466] [DMG] ICR moving to [AddedComma]
[1779542751.770] [27464:27466] [EM] <<< [E:3781i S:61192 M:214606419] (S) Msg TX from 000000000001B669 to 1:0000000000000001 [EBB6] [UDP:[fe80::e6b3:23ff:fe90:8844%wlp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:110)
[1779542751.770] [27464:27466] [EM] ??1 [E:3781i S:61192 M:214606419] (S) Msg Retransmission to 1:0000000000000001 scheduled for 581ms from now [State:Idle II:500 AI:300 AT:4000]
[1779542751.770] [27464:27466] [DMG] ICR moving to [AwaitingRe]
[1779542752.105] [27464:27466] [EM] >>> [E:3781i S:61192 M:205509566 (Ack:214606419)] (S) Msg RX from 1:0000000000000001 [EBB6] to 000000000001B669 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)
[1779542752.105] [27464:27466] [EM] Found matching exchange: 3781i, Delegate: 0x7f485c0011e8
[1779542752.105] [27464:27466] [EM] Rxd Ack; Removing MessageCounter:214606419 from Retrans Table on exchange 3781i
[1779542765.042] [27464:27466] [DMG] Time out! failed to receive invoke command response from Exchange: 3781i
[1779542765.042] [27464:27466] [CAM] AVStreamManagement: OnError. Error: src/app/CommandSender.cpp:354: CHIP Error 0x00000032: Timeout
[1779542765.042] [27464:27466] [DMG] ICR moving to [AwaitingDe]
[1779542765.042] [27464:27466] [CAM] AVStreamManagement: OnDone.
[1779542765.042] [27464:27466] [CAM] AVStreamManagement: Command VideoStreamAllocate has been successfully processed.

in esp32c6 device

I (189011) esp_matter_command: Received command 0x00000003 for endpoint 0x0001's cluster 0x00000551
E (189012) chip[DMG]: Failed to finalize command response: 3
E (189023) chip[DMG]: Failed to send InvokeResponseMessage
I (189024) chip[EM]: <<< [E:3781r S:27291 M:205509566 (Ack:214606419)] (S) Msg TX from 0000000000000001 to 1:000000000001B669 [EBB6] [UDP:[FE80::9D81:EB98:25FE:D84A%st2]:53035] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)