事前割り当てが大きいため、マター PacketBuffer プールが空です 私はマターデバイスFRDM-RW612に取り組んでいます。時々、PacketBuffer プールが空になっていることに気付きました。ログをここに添付しました [29889] [INFO] [IN] CASE Server received Sigma1 message . Starting handshake. EC 0x2005cd68
[29898] [INFO] [SC] Received Sigma1 msg
[29901] [TRACE] [SC] Found MRP parameters in the message
[29907] [TRACE] [SC] Peer assigned session key ID 582
[29912] [INFO] [DL] KVS, get key id:: f/1/g
[29916] [INFO] [DL] KVS, get key id:: f/1/k/0
[29922] [INFO] [SC] CASE matched destination ID: fabricIndex 1, NodeID 0x00000000000022B8
[30054] [INFO] [CSL] LWIP:PacketBuffer::New Request size=870, aAvailable=758, aReserved=112, MaxSize=64000
[30064] [INFO] [EM] <<< [E:14060r S:0 M:111174838] (U) Msg TX from 0000000000000000 to 0:0ED014D28E28AE99 [0000] [TCP:[FE80::FE84:A7FF:FE51:F90A]:40004] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:748)
[30083] [INFO] [SC] Sent Sigma2 msg
[30087] [ERR] [DL] Long dispatch time: 219 ms, for event type 3
[30092] [TRACE] [DL] DeviceEventCallback: 0x8016
[30214] [INFO] [EM] >>> [E:14060r S:0 M:239333775] (U) Msg RX from 0:0ED014D28E28AE99 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:594)
[30229] [TRACE] [EM] Found matching exchange: 14060r, Delegate: 0x2005bd74
[30236] [INFO] [SC] Received Sigma3 msg
[30288] [INFO] [DL] KVS, get key id:: g/sri
[30293] [ERR] [DL] KVS, key not found!
[30296] [INFO] [DL] KVS, put key id:: f/1/s/000000000001B669
[30304] [INFO] [DL] KVS, put key id:: g/s/HuzH83xHX2H4MZ6LiDY1cw==
[30312] [INFO] [DL] KVS, put key id:: g/sri
[30318] [TRACE] [SC] Sending status report. Protocol code 0, exchange 14060
[30325] [INFO] [CSL] LWIP:PacketBuffer::New Request size=120, aAvailable=8, aReserved=112, MaxSize=64000
[30334] [INFO] [EM] <<< [E:14060r S:0 M:111174839] (U) Msg TX from 0000000000000000 to 0:0ED014D28E28AE99 [0000] [TCP:[FE80::FE84:A7FF:FE51:F90A]:40004] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
[30354] [INFO] [SC] SecureSession[0x2005af10, LSID:25190]: State change 'kEstablishing' --> 'kActive'
[30363] [TRACE] [IN] SecureSession[0x2005af10]: Activated - Type:2 LSID:25190
[30371] [TRACE] [IN] New secure session activated for device <000000000001B669, 1>, LSID:25190 PSID:582!
[30380] [INFO] [IN] CASE Session established to peer: <000000000001B669, 1>
[30387] [TRACE] [IN] SecureSession[0x2005aff0]: Allocated Type:2 LSID:25191
[30394] [TRACE] [SC] Allocated SecureSession (0x2005aff0) - waiting for Sigma1 msg
[30402] [ERR] [DL] Long dispatch time: 114 ms, for event type 2
[30408] [INFO] [CSL] LWIP:PacketBuffer::New Request size=163, aAvailable=51, aReserved=112, MaxSize=64000
[30418] [INFO] [EM] >>> [E:14061r S:25190 M:250050934] (S) Msg RX from 1:000000000001B669 [578C] to 00000000000022B8 --- Type 0001:08 (IM:InvokeCommandRequest) (B:59)
[30433] [TRACE] [EM] Handling via exchange: 14061r, Delegate: 0x2005723c
[30440] [TRACE] [DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004
[30449] [INFO] [FS] GeneralCommissioning: Received CommissioningComplete
[30455] [INFO] [DL] KVS, put key id:: g/fs/c
[30461] [INFO] [DL] KVS, put key id:: f/1/m
[30467] [INFO] [FP] Metadata for Fabric 0x1 persisted to storage.
[30473] [INFO] [DL] KVS, put key id:: f/1/o
[30479] [INFO] [DL] KVS, put key id:: f/1/n
[30485] [INFO] [DL] KVS, put key id:: f/1/i
[30492] [INFO] [DL] KVS, put key id:: f/1/r
[30498] [INFO] [TS] Committing Last Known Good Time to storage: 2024-08-17T05:19:27
[30506] [INFO] [DL] KVS, put key id:: g/lkgt
[30510] [INFO] [DL] KVS, put key id:: g/fidx
[30516] [INFO] [ZCL] OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x51EB0A41B403578C, FabricId 0000000000000001, NodeId 00000000000022B8, VendorId 0xFFF1
[30532] [INFO] [DL] KVS, deleting key id:: g/fs/c
[30538] [INFO] [FS] GeneralCommissioning: Successfully commited pending fabric data
[30545] [INFO] [FS] Fail-safe cleanly disarmed
[30550] [TRACE] [DMG] Endpoint 0, Cluster 0x0000_0030 update version to e5eec16d
[30557] [INFO] [DL] endpointId 0x0000_0000 clusterId 0x0000_0030 attribute ID: 0x0000_0000 Type: 39 Value: 0, length 8
[30568] [INFO] [CSL] LWIP:PacketBuffer::New Request size=63940, aAvailable=63828, aReserved=112, MaxSize=64000
[30578] [ERR] [CSL] PacketBuffer: pool EMPTY.
[30582] [ERR] [DMG] Adding response failed: b. Returning failure instead.
[30590] [ERR] [DMG] Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 status 0x01 (no additional context)
[30599] [INFO] [CSL] LWIP:PacketBuffer::New Request size=63940, aAvailable=63828, aReserved=112, MaxSize=64000
[30609] [ERR] [CSL] PacketBuffer: pool EMPTY.
[30614] [ERR] [DMG] Failed to add command status: b
[30619] [TRACE] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 1
[30626] [TRACE] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 0
[30634] [ERR] [DMG] Failed to finalize command response: 3
[30640] [TRACE] [DMG] Command handler moving to [AwaitingDe]
[30645] [ERR] [DMG] Failed to send InvokeResponseMessage
[30650] [TRACE] [DMG] Command response sender moving to [AllInvokeR]
[30657] [ERR] [DL] Long dispatch time: 249 ms, for event type 3
[30663] [TRACE] [DL] DeviceEventCallback: 0x8018
[30667] [INFO] [SVR] Commissioning completed successfully
[30673] [INFO] [DIS] Updating services using commissioning mode 0
[30679] [INFO] [DIS] CHIP minimal mDNS started advertising.
[30685] [INFO] [CSL] LWIP:PacketBuffer::New Request size=624, aAvailable=512, aReserved=112, MaxSize=64000
[30695] [INFO] [CSL] LWIP:PacketBuffer::New Request size=1536, aAvailable=1424, aReserved=112, MaxSize=64000
[30705] [INFO] [CSL] LWIP:PacketBuffer::New Request size=624, aAvailable=512, aReserved=112, MaxSize=64000
[30716] [INFO] [CSL] LWIP:PacketBuffer::New Request size=1536, aAvailable=1424, aReserved=112, MaxSize=64000
[30726] [INFO] [CSL] LWIP:PacketBuffer::New Request size=624, aAvailable=512, aReserved=112, MaxSize=64000
[30736] [INFO] [CSL] LWIP:PacketBuffer::New Request size=1536, aAvailable=1424, aReserved=112, MaxSize=64000
[30746] [INFO] [CSL] LWIP:PacketBuffer::New Request size=624, aAvailable=512, aReserved=112, MaxSize=64000
[30757] [INFO] [CSL] LWIP:PacketBuffer::New Request size=1536, aAvailable=1424, aReserved=112, MaxSize=64000
[30767] [TRACE] [DL] Using WiFi MAC for hostname
[30772] [INFO] [DIS] Advertise operational node 51EB0A41B403578C-00000000000022B8
[30779] [TRACE] [DIS] Responding with _matter._tcp.local
[30784] [TRACE] [DIS] Responding with 51EB0A41B403578C-00000000000022B8._matter._tcp.local
[30793] [TRACE] [DIS] Responding with 51EB0A41B403578C-00000000000022B8._matter._tcp.local
[30801] [TRACE] [DIS] Responding with C095DA0152EF.local
[30806] [TRACE] [DIS] Responding with C095DA0152EF.local
[30812] [TRACE] [DIS] Responding with _I51EB0A41B403578C._sub._matter._tcp.local
[30819] [INFO] [DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: 51EB0A41B403578C-00000000000022B8.
[30830] [INFO] [CSL] LWIP:PacketBuffer::New Request size=624, aAvailable=512, aReserved=112, MaxSize=64000
[30841] [INFO] [CSL] LWIP:PacketBuffer::New Request size=1536, aAvailable=1424, aReserved=112, MaxSize=64000
[30851] [INFO] [CSL] LWIP:PacketBuffer::New Request size=624, aAvailable=512, aReserved=112, MaxSize=64000
[30861] [INFO] [CSL] LWIP:PacketBuffer::New Request size=1536, aAvailable=1424, aReserved=112, MaxSize=64000
[30871] [INFO] [DIS] mDNS service published: _matter._tcp
[30877] [TRACE] [DL] CHIPoBLE advertising set to off
[30882] [TRACE] [IN] Expiring all PASE sessions
[30886] [TRACE] [IN] SecureSession[0x2005ae30]: MarkForEviction Type:1 LSID:25189
[30894] [INFO] [SC] SecureSession[0x2005ae30, LSID:25189]: State change 'kActive' --> 'kPendingEviction'
[30903] [TRACE] [IN] SecureSession[0x2005ae30]: Released - Type:1 LSID:25189
[30910] [TRACE] [IN] Clearing BLE pending packets.
[30915] [INFO] [BLE] Releasing end point's BLE connection back to application.
[30922] [INFO] [DL] Closing BLE GATT connection (ConnId 00)
[30930] [TRACE] [ZCL] Commissioning complete, notify platform driver to persist network credentials.
[30939] [INFO] [DL] KVS, put key id:: wifi-ssid
[30944] [INFO] [DL] KVS, put key id:: wifi-pass
[30948] [TRACE] [DL] DeviceEventCallback: 0x800f
[30953] [ERR] [DL] Long dispatch time: 286 ms, for event type 32783
[30988] [INFO] [DL] Current number of connections: 0/1
[30993] [INFO] [DL] BLE GAP connection terminated (reason 0x16)
[30999] [TRACE] [BLE] No endpoint for connection error
[31004] [TRACE] [DL] DeviceEventCallback: 0x8007 注目すべき主な部分は次のとおりです。 [30418] [INFO] [EM] >>> [E:14061r S:25190 M:250050934] (S) Msg RX from 1:000000000001B669 [578C] to 00000000000022B8 --- Type 0001:08 (IM:InvokeCommandRequest) (B:59)
[30433] [TRACE] [EM] Handling via exchange: 14061r, Delegate: 0x2005723c
[30440] [TRACE] [DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004
[30449] [INFO] [FS] GeneralCommissioning: Received CommissioningComplete
[30455] [INFO] [DL] KVS, put key id:: g/fs/c
[30461] [INFO] [DL] KVS, put key id:: f/1/m
[30467] [INFO] [FP] Metadata for Fabric 0x1 persisted to storage.
[30473] [INFO] [DL] KVS, put key id:: f/1/o
[30479] [INFO] [DL] KVS, put key id:: f/1/n
[30485] [INFO] [DL] KVS, put key id:: f/1/i
[30492] [INFO] [DL] KVS, put key id:: f/1/r
[30498] [INFO] [TS] Committing Last Known Good Time to storage: 2024-08-17T05:19:27
[30506] [INFO] [DL] KVS, put key id:: g/lkgt
[30510] [INFO] [DL] KVS, put key id:: g/fidx
[30516] [INFO] [ZCL] OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x51EB0A41B403578C, FabricId 0000000000000001, NodeId 00000000000022B8, VendorId 0xFFF1
[30532] [INFO] [DL] KVS, deleting key id:: g/fs/c
[30538] [INFO] [FS] GeneralCommissioning: Successfully commited pending fabric data
[30545] [INFO] [FS] Fail-safe cleanly disarmed
[30550] [TRACE] [DMG] Endpoint 0, Cluster 0x0000_0030 update version to e5eec16d
[30557] [INFO] [DL] endpointId 0x0000_0000 clusterId 0x0000_0030 attribute ID: 0x0000_0000 Type: 39 Value: 0, length 8
[30568] [INFO] [CSL] LWIP:PacketBuffer::New Request size=63940, aAvailable=63828, aReserved=112, MaxSize=64000
[30578] [ERR] [CSL] PacketBuffer: pool EMPTY.
[30582] [ERR] [DMG] Adding response failed: b. Returning failure instead. 実際に受信されるメッセージ、InvokeCommandResponse は 59 バイト、または CommissioningComplete コマンドである可能性があります。しかし、なぜここでは約 64 KB が事前割り当て要件となるのでしょうか? トレースのためにPacketBuffer::New関数も追加しました PacketBufferHandle PacketBufferHandle::New(size_t aAvailableSize, uint16_t aReservedSize)
{
// Sanity check for kStructureSize to ensure that it matches the PacketBuffer size.
static_assert(PacketBuffer::kStructureSize == sizeof(PacketBuffer), "PacketBuffer size mismatch");
// Setting a static upper bound on kStructureSize to ensure the summation of all the sizes does not overflow.
static_assert(PacketBuffer::kStructureSize <= UINT16_MAX, "kStructureSize should not exceed UINT16_MAX.");
// Setting a static upper bound on the maximum buffer size allocation for regular sized messages (not large).
static_assert(PacketBuffer::kMaxSizeWithoutReserve <= UINT16_MAX, "kMaxSizeWithoutReserve should not exceed UINT16_MAX.");
#if INET_CONFIG_ENABLE_TCP_ENDPOINT
// Setting a static upper bound on the maximum buffer size allocation for
// large messages.
#if CHIP_SYSTEM_CONFIG_USE_LWIP
// LwIP based systems are internally limited to using a u16_t type as the size of a buffer.
static_assert(PacketBuffer::kLargeBufMaxSizeWithoutReserve <= UINT16_MAX,
"In LwIP, max size for Large payload buffers cannot exceed UINT16_MAX!");
#else
// Messages over TCP are framed using a length field that is 32 bits in
// length.
static_assert(PacketBuffer::kLargeBufMaxSizeWithoutReserve <= UINT32_MAX,
"Max size for Large payload buffers cannot exceed UINT32_MAX");
#endif // CHIP_SYSTEM_CONFIG_USE_LWIP
#endif // INET_CONFIG_ENABLE_TCP_ENDPOINT
// Ensure that aAvailableSize is bound within a max and is not big enough to cause overflow during
// subsequent addition of all the sizes.
if (aAvailableSize > UINT32_MAX)
{
ChipLogError(chipSystemLayer,
"PacketBuffer: AvailableSize of a buffer cannot exceed UINT32_MAX. aAvailableSize = 0x" ChipLogFormatX64,
ChipLogValueX64(static_cast (aAvailableSize)));
return PacketBufferHandle();
}
// Cast all to uint64_t and add. This cannot overflow because we have
// ensured that the maximal value of the summation is
// UINT32_MAX + UINT16_MAX + UINT16_MAX, which should always fit in
// a uint64_t variable.
uint64_t sumOfSizes = static_cast (aAvailableSize) + static_cast (aReservedSize) +
static_cast (PacketBuffer::kStructureSize);
uint64_t sumOfAvailAndReserved = static_cast (aAvailableSize) + static_cast (aReservedSize);
// Ensure that the sum fits in a size_t so that casting into size_t variables,
// viz., lBlockSize and lAllocSize, is safe.
if (!CanCastTo (sumOfSizes))
{
ChipLogError(chipSystemLayer,
"PacketBuffer: Sizes of allocation request are invalid. (aAvailableSize = " ChipLogFormatX64
", aReservedSize = " ChipLogFormatX64 ")",
ChipLogValueX64(static_cast (aAvailableSize)), ChipLogValueX64(static_cast (aReservedSize)));
return PacketBufferHandle();
}
#if CHIP_SYSTEM_CONFIG_USE_LWIP
// LwIP based APIs have a maximum buffer size of UINT16_MAX. Ensure that
// limit is met during allocation.
if (sumOfAvailAndReserved > UINT16_MAX)
{
ChipLogError(chipSystemLayer,
"LwIP based systems require total buffer size to be less than UINT16_MAX!"
"Attempted allocation size = " ChipLogFormatX64,
ChipLogValueX64(sumOfAvailAndReserved));
return PacketBufferHandle();
}
#endif // CHIP_SYSTEM_CONFIG_USE_LWIP
// sumOfAvailAndReserved is no larger than sumOfSizes, which we checked can be cast to
// size_t.
const size_t lAllocSize = static_cast (sumOfAvailAndReserved);
PacketBuffer * lPacket;
CHIP_SYSTEM_FAULT_INJECT(FaultInjection::kFault_PacketBufferNew, return PacketBufferHandle());
if (lAllocSize > PacketBuffer::kMaxAllocSize)
{
ChipLogError(chipSystemLayer, "PacketBuffer: allocation exceeding buffer capacity limits: %lu > %lu",
static_cast (lAllocSize), static_cast (PacketBuffer::kMaxAllocSize));
return PacketBufferHandle();
}
#if CHIP_SYSTEM_CONFIG_USE_LWIP
// This cast is safe because lAllocSize is no larger than
// kMaxSizeWithoutReserve, which fits in uint16_t.
lPacket = static_cast (
pbuf_alloc(PBUF_RAW, static_cast (lAllocSize), CHIP_SYSTEM_PACKETBUFFER_LWIP_PBUF_TYPE));
SYSTEM_STATS_UPDATE_LWIP_PBUF_COUNTS();
ChipLogProgress(chipSystemLayer,"LWIP:PacketBuffer::New Request size=%u, aAvailable=%u, aReserved=%u, MaxSize=%u",lAllocSize,aAvailableSize,aReservedSize,PacketBuffer::kMaxAllocSize);
#elif CHIP_SYSTEM_PACKETBUFFER_FROM_CHIP_POOL
#if !CHIP_SYSTEM_CONFIG_NO_LOCKING && CHIP_SYSTEM_CONFIG_FREERTOS_LOCKING
if (!sBufferPoolMutex.isInitialized())
{
Mutex::Init(sBufferPoolMutex);
}
#endif
LOCK_BUF_POOL();
lPacket = PacketBuffer::sFreeList;
if (lPacket != nullptr)
{
PacketBuffer::sFreeList = lPacket->ChainedBuffer();
SYSTEM_STATS_INCREMENT(chip::System::Stats::kSystemLayer_NumPacketBufs);
}
UNLOCK_BUF_POOL();
ChipLogProgress(chipSystemLayer,"CHIP POOL:PacketBuffer::New Request size=%u",lAllocSize);
#elif CHIP_SYSTEM_PACKETBUFFER_FROM_CHIP_HEAP
// sumOfSizes is essentially (kStructureSize + lAllocSize) which we already
// checked to fit in a size_t.
const size_t lBlockSize = static_cast (sumOfSizes);
lPacket = reinterpret_cast (chip::Platform::MemoryAlloc(lBlockSize));
SYSTEM_STATS_INCREMENT(chip::System::Stats::kSystemLayer_NumPacketBufs);
ChipLogProgress(chipSystemLayer,"CHIP HEAP:PacketBuffer::New Request size=%u",lAllocSize);
#else
#error "Unimplemented PacketBuffer storage case"
#endif
if (lPacket == nullptr)
{
ChipLogError(chipSystemLayer, "PacketBuffer: pool EMPTY.");
return PacketBufferHandle();
}
lPacket->payload = lPacket->ReserveStart() + aReservedSize;
lPacket->len = lPacket->tot_len = 0;
lPacket->next = nullptr;
lPacket->ref = 1;
#if CHIP_SYSTEM_PACKETBUFFER_FROM_CHIP_HEAP
lPacket->alloc_size = lAllocSize;
#endif
return PacketBufferHandle(lPacket);
} Re: Matter PacketBuffer Pool Empty due to Large Pre-Allocation 例はall-clusters-appです Re: Matter PacketBuffer Pool Empty due to Large Pre-Allocation あなたも元気でいらっしゃることを願っています。 セットアップはUbuntu 22.04、GN+Ninjaビルドです 私は以下のコマンドに従いました ~ git clone https://github.com/NXP/matter.git
~ cd matter
~ scripts/checkout_submodules.py --shallow --platform nxp --recursive
~ source ./scripts/activate.sh
~ ./third_party/nxp/nxp_matter_support/scripts/update_nxp_sdk.py --platform common
~ git submodule update --init --recursive
~ source ./scripts/activate.sh
~ cd examples/all-clusters-app/nxp/rt/rw61x
~ gn gen --args="chip_enable_wifi=true chip_inet_config_enable_tcp_endpoint=true board_version=\"frdm\"" out/debug
~ ninja -C out/debug マターのバージョンは、デフォルトの release/v1.4.0 です。 私はチップツールを大きなペイロードでテストしています chip-tool onoff on --allow-large-payload true [30568] [INFO] [CSL] LWIP:PacketBuffer::New Request size=63940, aAvailable=63828, aReserved=112, MaxSize=64000
[30578] [ERR] [CSL] PacketBuffer: pool EMPTY.
[30582] [ERR] [DMG] Adding response failed: b. Returning failure instead. 問題はマター/src/app/CommandHandlerImpl.cpp 内にありました。以下のコード行のように const size_t commandBufferMaxSize = mpResponder->GetCommandResponseMaxBufferSize();
auto commandPacket = System::PacketBufferHandle::New(commandBufferMaxSize);
VerifyOrReturnError(!commandPacket.IsNull(), CHIP_ERROR_NO_MEMORY); mpResponder->GetCommandResponseMaxBufferSize() は常に約 63,940 バイトを返し、この PacketBuffer は同じ .cpp 内の InvokeResponse と PrepareStatus の両方の関数で使用されます。ファイル。 これを解決するために、マター/src/system/SystemConfig.hのCHIP_SYSTEM_CONFIG_MAX_LARGE_BUFFER_SIZE_BYTESを64KBから10KBに変更しました。私のメッセージは10KBを超えることはないからです。ただし、ステータス レポートまたは InvokeResponse を送信するために最大サイズの PacketBuffer を割り当てることは、依然として過大評価です。 Re: Matter PacketBuffer Pool Empty due to Large Pre-Allocation こんにちは@farazahmed8さん、お元気でいらっしゃることを願っています。
問題を再現するために、マターと SDKs のリリース バージョン、および使用している例を共有していただけますか?また、MCUXpresso VS Code 拡張機能を使用しているか、Linux で GN/Ninja ビルドを使用しているかを確認してください。
記事全体を表示
