I: nRF5 802154 radio initialized I: 4 Sectors of 4096 bytes I: alloc wra: 3, c98 I: data wra: 3, 518 uart:~$ *** Booting Zephyr OS build v3.2.99-ncs1 *** I: Init CHIP stack I: 228 [DL]BLE address: C2:79:2D:8B:94:E3 I: SoftDevice Controller build revision: I: 6d 90 41 2a 38 e8 ad 17 |m.A*8... I: 29 a5 03 38 39 27 d7 85 |)..89'.. I: 1f 85 d8 e1 |.... I: 254 [DL]OpenThread started: OK I: 257 [DL]Setting OpenThread device type to ROUTER I: 262 [SVR]Server initializing... D: 265 [FP]Initializing FabricTable from persistent storage I: 271 [TS]Last Known Good Time: 2023-01-25T11:24:03 I: 277 [DMG]AccessControl: initializing I: 281 [DMG]Examples::AccessControlDelegate::Init I: 285 [DMG]AccessControl: setting I: 288 [DMG]DefaultAclStorage: initializing I: 292 [DMG]DefaultAclStorage: 0 entries loaded D: 296 [IN]UDP::Init bind&listen port=5540 E: 300 [IN]SO_REUSEPORT failed: 109 D: 304 [IN]UDP::Init bound to port=5540 D: 307 [IN]BLEBase::Init - setting/overriding transport D: 312 [IN]TransportMgr initialized D: 320 [DL]Using Thread extended MAC for hostname. I: 327 [ZCL]Using ZAP configuration... D: 331 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0 D: 340 [DMG]Failed to read stored attribute (1, 0x0000_0006, 0x0000_4003: a0 D: 348 [DMG]Failed to read stored attribute (1, 0x0000_0008, 0x0000_4000: a0 I: 355 [DMG]AccessControlCluster: initializing D: 359 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 2c2ee462 D: 366 [DL]Boot reason: 1 D: 368 [ZCL]GeneralDiagnostics: OnDeviceReboot D: 372 [DMG]Endpoint 0, Cluster 0x0000_0033 update version to cc4521f2 D: 379 [EVL]LogEvent event number: 0x0000000000020000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x000000000000017A I: 392 [ZCL]Initiating Admin Commissioning cluster. D: 397 [DMG]Endpoint 1, Cluster 0x0000_0003 update version to 2eb9dc3c D: 404 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 9b2baf50 D: 410 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 9b2baf51 I: 416 [ZCL]On/Off set value: 1 0 I: 419 [ZCL]On/off already set to new value D: 424 [DMG]Endpoint 1, Cluster 0x0000_0008 update version to d5b5ac03 I: 430 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 D: 436 [ZCL]LED is off. Try to use move-to-level-with-on-off instead of move-to-level D: 446 [IN]SecureSession[0x20003650]: Allocated Type:1 LSID:493 D: 452 [SC]Assigned local session key ID 493 D: 456 [SC]Waiting for PBKDF param request D: 460 [DL]CHIPoBLE advertising set to on I: 463 [DIS]Updating services using commissioning mode 1 D: 468 [DL]Using Thread extended MAC for hostname. D: 473 [DL]Using Thread extended MAC for hostname. I: 479 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 488 [DIS]Failed to advertise commissionable node: 3 E: 493 [DIS]Failed to finalize service update: 1c I: 497 [DIS]Updating services using commissioning mode 1 D: 502 [DL]Using Thread extended MAC for hostname. D: 507 [DL]Using Thread extended MAC for hostname. I: 512 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 E: 521 [DIS]Failed to advertise commissionable node: 3 E: 526 [DIS]Failed to finalize service update: 1c I: 531 [DIS]Delaying proxy of operational discovery: missing delegate I: 537 [IN]CASE Server enabling CASE session setups D: 542 [IN]SecureSession[0x20003708]: Allocated Type:2 LSID:494 D: 547 [SC]Allocated SecureSession (0x20003708) - waiting for Sigma1 msg I: 554 [SVR]Joining Multicast groups D: 557 [ZCL]Emitting StartUp event D: 560 [EVL]LogEvent event number: 0x0000000000020001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x0000000000000230 I: 574 [SVR]Server Listening... I: 577 [DL]Device Configuration: I: 581 [DL] Serial Number: 11223344556677889900 I: 585 [DL] Vendor Id: 65521 (0xFFF1) I: 588 [DL] Product Id: 32773 (0x8005) I: 593 [DL] Hardware Version: 0 I: 596 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 602 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) I: 609 [DL] Manufacturing Date: (not set) I: 613 [DL] Device Type: 65535 (0xFFFF) I: 618 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00] I: 623 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 629 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00 I: 638 [SVR]Manual pairing code: [34970112332] I: 643 [DL]CHIP task running I: 648 [DL]CHIPoBLE advertising started D: 652 [DMG]Endpoint 1, Cluster 0x0000_0006 update version to 3748b652 I: 658 [ZCL]Cluster OnOff: attribute OnOff set to 0 D: 663 [DMG]Endpoint 1, Cluster 0x0000_0008 update version to d5b5ac04 I: 669 [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254 D: 675 [ZCL]LED is off. Try to use move-to-level-with-on-off instead of move-to-level I: 685 [DL]NFC Tag emulation started I: 18647 [DL]BLE connection established (ConnId: 0x00) I: 18652 [DL]Current number of connections: 1/2 I: 18657 [DL]CHIPoBLE advertising stopped I: 18660 [DL]NFC Tag emulation stopped D: 19239 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 19246 [BLE]local and remote recv window sizes = 5 I: 19251 [BLE]selected BTP version 4 I: 19254 [BLE]using BTP fragment sizes rx 244 / tx 244. D: 19337 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 19341 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 19349 [IN]BLE EndPoint 0x20012270 Connection Complete I: 19354 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247) D: 19483 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19532 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 19540 [EM]>>> [E:890r M:67296115] (U) Msg RX from 0:405068CC484636AD [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) D: 19551 [EM]Handling via exchange: 890r, Delegate: 0x20005834 D: 19557 [SC]Received PBKDF param request D: 19560 [SC]Peer assigned session ID 54719 D: 19564 [SC]Found MRP parameters in the message D: 19569 [SC]Including MRP parameters in PBKDF param response I: 19575 [EM]<<< [E:890r M:66570300] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) I: 19587 [IN](U) Sending msg 66570300 to IP address 'BLE' D: 19592 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 140) D: 19599 [SC]Sent PBKDF param response D: 19678 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 19776 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 19783 [EM]>>> [E:890r M:67296116] (U) Msg RX from 0:405068CC484636AD [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) D: 19794 [EM]Found matching exchange: 890r, Delegate: 0x20005834 D: 19800 [SC]Received spake2p msg1 I: 21725 [EM]<<< [E:890r M:66570301] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) I: 21735 [IN](U) Sending msg 66570301 to IP address 'BLE' D: 21741 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132) D: 21748 [SC]Sent spake2p msg2 E: 21751 [DL]Long dispatch time: 1975 ms, for event type 16388 D: 21823 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 21831 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 21839 [EM]>>> [E:890r M:67296117] (U) Msg RX from 0:405068CC484636AD [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) D: 21849 [EM]Found matching exchange: 890r, Delegate: 0x20005834 D: 21855 [SC]Received spake2p msg3 D: 21859 [SC]Sending status report. Protocol code 0, exchange 890 I: 21865 [EM]<<< [E:890r M:66570302] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) I: 21876 [IN](U) Sending msg 66570302 to IP address 'BLE' D: 21881 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 21889 [SC]SecureSession[0x20003650]: Moving from state 'kEstablishing' --> 'kActive' D: 21897 [IN]SecureSession[0x20003650]: Activated - Type:1 LSID:493 D: 21903 [IN]New secure session activated for device , LSID:493 PSID:54719! I: 21912 [SVR]Commissioning completed session establishment step I: 21918 [DIS]Updating services using commissioning mode 0 D: 21924 [DL]Using Thread extended MAC for hostname. D: 21929 [DL]Using Thread extended MAC for hostname. I: 21934 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 E: 21943 [DIS]Failed to advertise extended commissionable node: 3 D: 21949 [DIS]Scheduling extended discovery timeout in 900s E: 21954 [DIS]Failed to finalize service update: 1c D: 21959 [DL]CHIPoBLE advertising set to off I: 21963 [SVR]Device completed Rendezvous process E: 21967 [DL]Long dispatch time: 136 ms, for event type 16388 D: 21974 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 21982 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 21990 [EM]>>> [E:891r M:4175236] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 22000 [EM]Handling via exchange: 891r, Delegate: 0x2000fc3c D: 22005 [IM]Received Read request D: 22009 [DMG]IM RH moving to [GeneratingReports] D: 22014 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 22023 [DMG] Cluster 28, Attribute 4 is dirty D: 22028 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) D: 22037 [DMG] Cluster 28, Attribute 2 is dirty D: 22042 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 22050 [DMG] Sending report (payload has 64 bytes)... I: 22057 [EM]<<< [E:891r M:14121613] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 22067 [IN](S) Sending msg 14121613 on secure session with LSID: 493 D: 22073 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 99) D: 22081 [DMG] OnReportConfirm: NumReports = 0 D: 22085 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 22093 [DMG]IM RH moving to [AwaitingDestruction] D: 22097 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 22165 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22172 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22180 [EM]>>> [E:892r M:4175237] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 22190 [EM]Handling via exchange: 892r, Delegate: 0x2000fc3c D: 22196 [IM]Received Read request D: 22200 [DMG]IM RH moving to [GeneratingReports] D: 22204 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 22213 [DMG] Cluster 3e, Attribute 2 is dirty D: 22218 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 22227 [DMG] Sending report (payload has 36 bytes)... I: 22233 [EM]<<< [E:892r M:14121614] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 22243 [IN](S) Sending msg 14121614 on secure session with LSID: 493 D: 22249 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 22256 [DMG] OnReportConfirm: NumReports = 0 D: 22261 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 22269 [DMG]IM RH moving to [AwaitingDestruction] D: 22273 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 22311 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22319 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22326 [EM]>>> [E:893r M:4175238] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) D: 22336 [EM]Handling via exchange: 893r, Delegate: 0x2000fc3c D: 22342 [IM]Received Read request D: 22346 [DMG]IM RH moving to [GeneratingReports] D: 22350 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 22359 [DMG] Cluster 3e, Attribute 3 is dirty D: 22364 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0003 (expanded=0) D: 22373 [DMG] Sending report (payload has 36 bytes)... I: 22379 [EM]<<< [E:893r M:14121615] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) I: 22389 [IN](S) Sending msg 14121615 on secure session with LSID: 493 D: 22395 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 22403 [DMG] OnReportConfirm: NumReports = 0 D: 22408 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 22415 [DMG]IM RH moving to [AwaitingDestruction] D: 22420 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 22457 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22465 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22473 [EM]>>> [E:894r M:4175239] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:0a (IM:TimedRequest) D: 22483 [EM]Handling via exchange: 894r, Delegate: 0x2000fc3c D: 22488 [DMG]Got Timed Request with timeout 10000: handler 0x20010038 exchange 894r I: 22497 [EM]<<< [E:894r M:14121616] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:01 (IM:StatusResponse) I: 22507 [IN](S) Sending msg 14121616 on secure session with LSID: 493 D: 22513 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 22521 [DMG]Timed Request time limit 0x0000000000007F09: handler 0x20010038 exchange 894r D: 22603 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22611 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22619 [EM]>>> [E:894r M:4175240] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 22630 [EM]Found matching exchange: 894r, Delegate: 0x20010038 D: 22636 [DMG]Timed following action arrived at 0x000000000000586B: handler 0x20010038 exchange 894r D: 22644 [DMG]Handing timed invoke to IM engine: handler 0x20010038 exchange 894r D: 22652 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 I: 22660 [FS]GeneralCommissioning: Received ArmFailSafe (900s) D: 22666 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 2c2ee463 D: 22672 [DMG]Command handler moving to [ Preparing] D: 22677 [DMG]Command handler moving to [AddingComm] D: 22681 [DMG]Command handler moving to [AddedComma] D: 22686 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 22694 [EM]<<< [E:894r M:14121617] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 22704 [IN](S) Sending msg 14121617 on secure session with LSID: 493 D: 22711 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 22718 [DMG]Command handler moving to [CommandSen] D: 22723 [DMG]Command handler moving to [AwaitingDe] E: 22728 [DL]Long dispatch time: 117 ms, for event type 16388 D: 22798 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22806 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 22814 [EM]>>> [E:895r M:4175241] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 22825 [EM]Handling via exchange: 895r, Delegate: 0x2000fc3c D: 22831 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 22838 [ZCL]OpCreds: Certificate Chain request received for PAI D: 22844 [DMG]Command handler moving to [ Preparing] D: 22849 [DMG]Command handler moving to [AddingComm] D: 22854 [DMG]Command handler moving to [AddedComma] D: 22859 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 22868 [EM]<<< [E:895r M:14121618] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 22879 [IN](S) Sending msg 14121618 on secure session with LSID: 493 D: 22885 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 22893 [DMG]Command handler moving to [CommandSen] D: 22898 [DMG]Command handler moving to [AwaitingDe] D: 22944 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 22952 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 23042 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 23049 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48) D: 23140 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 23147 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 23155 [EM]>>> [E:896r M:4175242] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 23166 [EM]Handling via exchange: 896r, Delegate: 0x2000fc3c D: 23172 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 I: 23180 [ZCL]OpCreds: Certificate Chain request received for DAC D: 23186 [DMG]Command handler moving to [ Preparing] D: 23190 [DMG]Command handler moving to [AddingComm] D: 23195 [DMG]Command handler moving to [AddedComma] D: 23200 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 23209 [EM]<<< [E:896r M:14121619] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 23220 [IN](S) Sending msg 14121619 on secure session with LSID: 493 D: 23226 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 23234 [DMG]Command handler moving to [CommandSen] D: 23239 [DMG]Command handler moving to [AwaitingDe] D: 23285 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 23293 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 23383 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 23391 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77) D: 23480 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 25431 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 25439 [EM]>>> [E:897r M:4175243] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 25450 [EM]Handling via exchange: 897r, Delegate: 0x2000fc3c D: 25456 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 I: 25463 [ZCL]OpCreds: Received a CSRRequest command D: 25468 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0 I: 25664 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded I: 25699 [ZCL]OpCreds: CSRRequest successful. D: 25703 [DMG]Command handler moving to [ Preparing] D: 25708 [DMG]Command handler moving to [AddingComm] D: 25713 [DMG]Command handler moving to [AddedComma] D: 25718 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 25726 [EM]<<< [E:897r M:14121620] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 25737 [IN](S) Sending msg 14121620 on secure session with LSID: 493 D: 25743 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 25751 [DMG]Command handler moving to [CommandSen] D: 25756 [DMG]Command handler moving to [AwaitingDe] E: 25761 [DL]Long dispatch time: 329 ms, for event type 16388 D: 25835 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 25843 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 138) D: 25925 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 28311 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 29706 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 29796 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 29805 [EM]>>> [E:898r M:4175244] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 29816 [EM]Handling via exchange: 898r, Delegate: 0x2000fc3c D: 29822 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B I: 29829 [ZCL]OpCreds: Received an AddTrustedRootCertificate command I: 29893 [ZCL]OpCreds: AddTrustedRootCertificate successful. D: 29898 [DMG]Command handler moving to [ Preparing] D: 29903 [DMG]Command handler moving to [AddingComm] D: 29908 [DMG]Command handler moving to [AddedComma] D: 29912 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 29920 [EM]<<< [E:898r M:14121621] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) I: 29931 [IN](S) Sending msg 14121621 on secure session with LSID: 493 D: 29937 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68) D: 29944 [DMG]Command handler moving to [CommandSen] D: 29949 [DMG]Command handler moving to [AwaitingDe] E: 29954 [DL]Long dispatch time: 158 ms, for event type 16388 D: 30020 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 30029 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 30112 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) D: 30201 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 30212 [EM]>>> [E:899r M:4175245] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) D: 30222 [EM]Handling via exchange: 899r, Delegate: 0x2000fc3c D: 30229 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 I: 30236 [ZCL]OpCreds: Received an AddNOC command I: 30244 [FP]Validating NOC chain I: 30361 [FP]NOC chain validation successful I: 30365 [FP]Added new fabric at index: 0x1 I: 30369 [FP]Assigned compressed fabric ID: 0xF6C719953D1526E0, node ID: 0x2E660045E7AA8127 I: 30377 [TS]Last Known Good Time: 2023-01-25T11:24:03 I: 30382 [TS]New proposed Last Known Good Time: 2023-02-01T06:40:32 I: 30389 [TS]Updating pending Last Known Good Time to 2023-02-01T06:40:32 D: 30395 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 304df8cc D: 30402 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 304df8cd D: 30437 [EVL]LogEvent event number: 0x0000000000020002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x00000000000076E4 I: 30451 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0xFFFFFFFD00000001 D: 30459 [DL]Using Thread extended MAC for hostname. I: 30464 [DIS]Advertise operational node F6C719953D1526E0-2E660045E7AA8127 D: 30471 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 304df8ce D: 30478 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 304df8cf D: 30484 [DMG]Command handler moving to [ Preparing] D: 30489 [DMG]Command handler moving to [AddingComm] D: 30494 [DMG]Command handler moving to [AddedComma] I: 30498 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC D: 30505 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 30512 [EM]<<< [E:899r M:14121622] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:09 (IM:InvokeCommandResponse) I: 30523 [IN](S) Sending msg 14121622 on secure session with LSID: 493 D: 30529 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 30537 [DMG]Command handler moving to [CommandSen] D: 30541 [DMG]Command handler moving to [AwaitingDe] E: 30546 [DL]Long dispatch time: 345 ms, for event type 16388 D: 30606 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 30614 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 30622 [EM]>>> [E:900r M:4175246] (S) Msg RX from 1:FFFFFFFB00000000 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 30631 [EM]Handling via exchange: 900r, Delegate: 0x2000fc3c D: 30637 [IM]Received Read request D: 30641 [DMG]IM RH moving to [GeneratingReports] D: 30645 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 30654 [DMG] Cluster 31, Attribute fffc is dirty D: 30660 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) D: 30669 [DMG] Sending report (payload has 37 bytes)... I: 30675 [EM]<<< [E:900r M:14121623] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:05 (IM:ReportData) I: 30684 [IN](S) Sending msg 14121623 on secure session with LSID: 493 D: 30691 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72) D: 30699 [DMG] OnReportConfirm: NumReports = 0 D: 30703 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 30710 [DMG]IM RH moving to [AwaitingDestruction] D: 30715 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 30785 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 32091 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 32098 [EM]>>> [E:901r M:4175247] (S) Msg RX from 1:FFFFFFFB00000000 [26E0] --- Type 0001:0a (IM:TimedRequest) D: 32108 [EM]Handling via exchange: 901r, Delegate: 0x2000fc3c D: 32114 [DMG]Got Timed Request with timeout 15000: handler 0x20010038 exchange 901r I: 32122 [EM]<<< [E:901r M:14121624] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:01 (IM:StatusResponse) I: 32132 [IN](S) Sending msg 14121624 on secure session with LSID: 493 D: 32139 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 32146 [DMG]Timed Request time limit 0x000000000000B82A: handler 0x20010038 exchange 901r D: 32226 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 32234 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 32242 [EM]>>> [E:901r M:4175248] (S) Msg RX from 1:FFFFFFFB00000000 [26E0] --- Type 0001:08 (IM:InvokeCommandRequest) D: 32252 [EM]Found matching exchange: 901r, Delegate: 0x20010038 D: 32258 [DMG]Timed following action arrived at 0x0000000000007E02: handler 0x20010038 exchange 901r D: 32267 [DMG]Handing timed invoke to IM engine: handler 0x20010038 exchange 901r D: 32275 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0000 D: 32285 [DMG]Decreasing reference count for CommandHandler, remaining 1 D: 32291 [DL]OpenThread State Changed (Flags: 0x01009009) D: 32296 [DL] Network Name: OpenThread D: 32300 [DL] PAN Id: 0x127B D: 32303 [DL] Extended PAN Id: 0xDEAD00BEEF00CAFE D: 32308 [DL] Channel: 11 D: 32310 [DL] Mesh Prefix: fdde:ad00:beef::/64 D: 32315 [DL] Thread Unicast Addresses: D: 32319 [DL] fe80::51:fe3d:217b:7bb9/64 valid preferred I: 32382 [DL]Thread Network: ST-5031317040 Panid 0xa66e Channel 11 RSSI -59 LQI 136 Version 4 I: 33875 [DL]Thread Network: NEST-PAN-60D8 Panid 0x60d8 Channel 16 RSSI -40 LQI 212 Version 4 D: 34742 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3) D: 34835 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37145 [DL]OpenThread State Changed (Flags: 0x00008000) D: 37151 [DL] Network Name: OpenThread D: 37154 [DL] PAN Id: 0xFFFF D: 37157 [DL] Extended PAN Id: 0xDEAD00BEEF00CAFE D: 37162 [DL] Channel: 11 D: 37164 [DL] Mesh Prefix: fdde:ad00:beef::/64 D: 37170 [DMG]Command handler moving to [ Preparing] D: 37175 [DMG]Command handler moving to [AddingComm] D: 37180 [DMG]Command handler moving to [AddedComma] D: 37185 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 2c2ee464 D: 37191 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 37199 [EM]<<< [E:901r M:14121625] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:09 (IM:InvokeCommandResponse) I: 37209 [IN](S) Sending msg 14121625 on secure session with LSID: 493 D: 37216 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 180) D: 37223 [DMG]Command handler moving to [CommandSen] D: 37228 [DMG]Command handler moving to [AwaitingDe] D: 37233 [DL]OpenThread State Changed (Flags: 0x01002002) D: 37238 [DL] Thread Unicast Addresses: D: 37311 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37319 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37326 [EM]>>> [E:902r M:4175249] (S) Msg RX from 1:FFFFFFFB00000000 [26E0] --- Type 0001:0a (IM:TimedRequest) D: 37336 [EM]Handling via exchange: 902r, Delegate: 0x2000fc3c D: 37342 [DMG]Got Timed Request with timeout 10000: handler 0x20010038 exchange 902r I: 37350 [EM]<<< [E:902r M:14121626] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:01 (IM:StatusResponse) I: 37361 [IN](S) Sending msg 14121626 on secure session with LSID: 493 D: 37367 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 37375 [DMG]Timed Request time limit 0x000000000000B90E: handler 0x20010038 exchange 902r D: 37445 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37491 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37499 [EM]>>> [E:902r M:4175250] (S) Msg RX from 1:FFFFFFFB00000000 [26E0] --- Type 0001:08 (IM:InvokeCommandRequest) D: 37510 [EM]Found matching exchange: 902r, Delegate: 0x20010038 D: 37515 [DMG]Timed following action arrived at 0x000000000000928B: handler 0x20010038 exchange 902r D: 37524 [DMG]Handing timed invoke to IM engine: handler 0x20010038 exchange 902r D: 37532 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 D: 37545 [DMG]Command handler moving to [ Preparing] D: 37550 [DMG]Command handler moving to [AddingComm] D: 37555 [DMG]Command handler moving to [AddedComma] D: 37559 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 2c2ee465 D: 37566 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 37573 [EM]<<< [E:902r M:14121627] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:09 (IM:InvokeCommandResponse) I: 37584 [IN](S) Sending msg 14121627 on secure session with LSID: 493 D: 37591 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 37598 [DMG]Command handler moving to [CommandSen] D: 37603 [DMG]Command handler moving to [AwaitingDe] E: 37608 [DL]Long dispatch time: 116 ms, for event type 16388 D: 37671 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37679 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37686 [EM]>>> [E:903r M:4175251] (S) Msg RX from 1:FFFFFFFB00000000 [26E0] --- Type 0001:0a (IM:TimedRequest) D: 37696 [EM]Handling via exchange: 903r, Delegate: 0x2000fc3c D: 37702 [DMG]Got Timed Request with timeout 10000: handler 0x20010038 exchange 903r I: 37710 [EM]<<< [E:903r M:14121628] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:01 (IM:StatusResponse) I: 37721 [IN](S) Sending msg 14121628 on secure session with LSID: 493 D: 37727 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 43) D: 37734 [DMG]Timed Request time limit 0x000000000000BA76: handler 0x20010038 exchange 903r D: 37806 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 37814 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 37822 [EM]>>> [E:903r M:4175252] (S) Msg RX from 1:FFFFFFFB00000000 [26E0] --- Type 0001:08 (IM:InvokeCommandRequest) D: 37832 [EM]Found matching exchange: 903r, Delegate: 0x20010038 D: 37838 [DMG]Timed following action arrived at 0x00000000000093CE: handler 0x20010038 exchange 903r D: 37847 [DMG]Handing timed invoke to IM engine: handler 0x20010038 exchange 903r D: 37855 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 D: 37874 [DMG]Decreasing reference count for CommandHandler, remaining 1 D: 37880 [DL]OpenThread State Changed (Flags: 0x1006c100) D: 37885 [DL] Network Name: OpenThread D: 37889 [DL] PAN Id: 0xA66E D: 37892 [DL] Extended PAN Id: 0x0839FB52516142A3 D: 37897 [DL] Channel: 11 D: 37900 [DL] Mesh Prefix: fdde:ad00:beef::/64 D: 37905 [DL]OpenThread State Changed (Flags: 0x1100101d) D: 37910 [DL] Device Role: DETACHED D: 37914 [DL] Thread Unicast Addresses: D: 37918 [DL] fdde:ad00:beef:0:bb5e:acc5:3d61:a6c8/64 valid D: 37924 [DL] fe80::51:fe3d:217b:7bb9/64 valid preferred I: 39119 [DL]SRP Client was started, detected server: fd6e:d157:02b4:cdbf:bcea:f929:48fe:1a70 D: 39129 [DL]OpenThread State Changed (Flags: 0x301932b7) D: 39134 [DL] Device Role: CHILD D: 39137 [DL] Network Name: ST-5031317040 D: 39141 [DL] PAN Id: 0xA66E D: 39144 [DL] Extended PAN Id: 0x0839FB52516142A3 D: 39148 [DL] Channel: 11 D: 39151 [DL] Mesh Prefix: fd6e:d157:2b4:cdbf::/64 D: 39156 [DL] Partition Id: 0x19E0524B D: 39160 [DL] Thread Unicast Addresses: D: 39163 [DL] fd13:7ccf:ced4:1:a0e4:6aac:a284:e276/64 valid preferred D: 39170 [DL] fd6e:d157:2b4:cdbf:0:ff:fe00:c808/64 valid rloc D: 39176 [DL] fd6e:d157:2b4:cdbf:bb5e:acc5:3d61:a6c8/64 valid D: 39182 [DL] fe80::51:fe3d:217b:7bb9/64 valid preferred D: 39190 [DL]OpenThread State Changed (Flags: 0x00000001) D: 39195 [DL] Thread Unicast Addresses: D: 39199 [DL] fd13:7ccf:ced4:1:a0e4:6aac:a284:e276/64 valid preferred D: 39369 [DL] fd6e:d157:2b4:cdbf:0:ff:fe00:c808/64 valid rloc D: 39375 [DL] fd6e:d157:2b4:cdbf:bb5e:acc5:3d61:a6c8/64 valid D: 39384 [DL] fe80::51:fe3d:217b:7bb9/64 valid preferred E: 39446 [DL]Long dispatch time: 256 ms, for event type 32777 D: 39454 [DMG]Command handler moving to [ Preparing] D: 39459 [DMG]Command handler moving to [AddingComm] D: 39464 [DMG]Command handler moving to [AddedComma] D: 39469 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 2c2ee466 D: 39476 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 39485 [EM]<<< [E:903r M:14121629] (S) Msg TX to 1:FFFFFFFB00000000 [26E0] --- Type 0001:09 (IM:InvokeCommandResponse) I: 39496 [IN](S) Sending msg 14121629 on secure session with LSID: 493 D: 39502 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 70) D: 39511 [DMG]Command handler moving to [CommandSen] D: 39516 [DMG]Command handler moving to [AwaitingDe] D: 39520 [DL]Using Thread extended MAC for hostname. I: 39525 [DIS]Advertise operational node F6C719953D1526E0-2E660045E7AA8127 I: 39532 [SVR]Operational advertising enabled D: 39561 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39595 [DL]SRP update succeeded I: 39598 [DIS]Setting operational delegate post init I: 39607 [SWU]Stopping the watchdog timer I: 39611 [SWU]Starting the periodic query timer, timeout: 86400 seconds I: 39617 [DIS]Updating services using commissioning mode 0 D: 39623 [DL]Using Thread extended MAC for hostname. I: 39627 [DIS]Advertise operational node F6C719953D1526E0-2E660045E7AA8127 I: 39634 [DL]advertising srp service: F6C719953D1526E0-2E660045E7AA8127._matter._tcp D: 39642 [DL]Using Thread extended MAC for hostname. I: 39648 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 I: 39658 [DL]advertising srp service: AB69C6E1F514A060._matterc._udp D: 39664 [DMG]Endpoint 0, Cluster 0x0000_002A update version to 68d60f11 D: 39670 [DMG]Endpoint 0, Cluster 0x0000_002A update version to 68d60f12 D: 41350 [DL]SRP update succeeded I: 41621 [EM]>>> [E:6653r M:241297066] (U) Msg RX from 0:820BF9FEB6EE587B [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) D: 41633 [EM]Handling via exchange: 6653r, Delegate: 0x200042c0 I: 41639 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004fd0 I: 41646 [IN]CASE Server disabling CASE session setups I: 41651 [EM]<<< [E:6653r M:66570303 (Ack:241297066)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 41664 [IN](U) Sending msg 66570303 to IP address 'UDP:[fd13:7ccf:ced4:1:e6cc:8a61:106c:41a6]:35362' D: 41674 [EM]Flushed pending ack for MessageCounter:241297066 on exchange 6653r I: 41681 [SC]Received Sigma1 msg D: 41684 [SC]Found MRP parameters in the message D: 41689 [SC]Peer assigned session key ID 41927 I: 41697 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x2E660045E7AA8127 D: 41923 [SC]Including MRP parameters I: 41927 [EM]<<< [E:6653r M:66570304 (Ack:241297066)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) I: 41940 [IN](U) Sending msg 66570304 to IP address 'UDP:[fd13:7ccf:ced4:1:e6cc:8a61:106c:41a6]:35362' I: 41951 [SC]Sent Sigma2 msg D: 42036 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 42269 [EM]>>> [E:6653r M:241297067 (Ack:66570304)] (U) Msg RX from 0:820BF9FEB6EE587B [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) D: 42281 [EM]Found matching exchange: 6653r, Delegate: 0x200042dc D: 42287 [EM]Rxd Ack; Removing MessageCounter:66570304 from Retrans Table on exchange 6653r I: 42296 [EM]<<< [E:6653r M:66570305 (Ack:241297067)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 42308 [IN](U) Sending msg 66570305 to IP address 'UDP:[fd13:7ccf:ced4:1:e6cc:8a61:106c:41a6]:35362' D: 42319 [EM]Flushed pending ack for MessageCounter:241297067 on exchange 6653r I: 42326 [SC]Received Sigma3 msg E: 42334 [SC]The device does not support GetClock_RealTimeMS() API: 3. Falling back to Last Known Good UTC Time D: 42679 [SC]Sending status report. Protocol code 0, exchange 6653 I: 42685 [EM]<<< [E:6653r M:66570306 (Ack:241297067)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) I: 42698 [IN](U) Sending msg 66570306 to IP address 'UDP:[fd13:7ccf:ced4:1:e6cc:8a61:106c:41a6]:35362' I: 42709 [SC]SecureSession[0x20003708]: Moving from state 'kEstablishing' --> 'kActive' D: 42717 [IN]SecureSession[0x20003708]: Activated - Type:2 LSID:494 D: 42724 [IN]New secure session activated for device <4EDF6C6116ACADD8, 1>, LSID:494 PSID:41927! I: 42732 [IN]CASE Session established to peer: <4EDF6C6116ACADD8, 1> I: 42738 [IN]CASE Server enabling CASE session setups D: 42744 [IN]SecureSession[0x200037c0]: Allocated Type:2 LSID:495 D: 42750 [SC]Allocated SecureSession (0x200037c0) - waiting for Sigma1 msg I: 42759 [EM]>>> [E:6653r M:241297068 (Ack:66570306)] (U) Msg RX from 0:820BF9FEB6EE587B [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 42771 [EM]Found matching exchange: 6653r, Delegate: (nil) D: 42779 [EM]Rxd Ack; Removing MessageCounter:66570306 from Retrans Table on exchange 6653r I: 42788 [EM]>>> [E:6654r M:13203502] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 42798 [EM]Handling via exchange: 6654r, Delegate: 0x2000fc3c D: 42804 [IM]Received Read request D: 42808 [DMG]IM RH moving to [GeneratingReports] D: 42813 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 42821 [DMG] Cluster 3e, Attribute 5 is dirty D: 42827 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0005 (expanded=0) D: 42836 [DMG] Cluster 3e, Attribute 2 is dirty D: 42841 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 42850 [DMG] Cluster 3e, Attribute 1 is dirty D: 42855 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 42864 [DMG] Sending report (payload has 214 bytes)... I: 42871 [EM]<<< [E:6654r M:140720498 (Ack:13203502)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 42882 [IN](S) Sending msg 140720498 on secure session with LSID: 494 D: 42891 [DMG] OnReportConfirm: NumReports = 0 D: 42895 [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages D: 42903 [DMG]IM RH moving to [AwaitingDestruction] D: 42908 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 42953 [EM]>>> [E:6654r M:13203503 (Ack:140720498)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 42966 [EM]Found matching exchange: 6654r, Delegate: (nil) D: 42971 [EM]Rxd Ack; Removing MessageCounter:140720498 from Retrans Table on exchange 6654r I: 42983 [EM]>>> [E:6655r M:13203504] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:03 (IM:SubscribeRequest) D: 42993 [EM]Handling via exchange: 6655r, Delegate: 0x2000fc3c D: 42999 [IM]Received Subscribe request I: 43003 [DMG]Final negotiated min/max parameters: Min = 1s, Max = 60s D: 43010 [DMG]IM RH moving to [GeneratingReports] D: 43014 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 43023 [DMG] Cluster 28, Attribute 2 is dirty D: 43028 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) D: 43037 [DMG] Sending report (payload has 41 bytes)... D: 43043 [DMG]IM RH moving to [AwaitingReportResponse] I: 43048 [EM]<<< [E:6655r M:140720499 (Ack:13203504)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 43060 [IN](S) Sending msg 140720499 on secure session with LSID: 494 D: 43067 [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages D: 43075 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 43107 [EM]>>> [E:6655r M:13203505 (Ack:140720499)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 43119 [EM]Found matching exchange: 6655r, Delegate: 0x200116e4 D: 43125 [EM]Rxd Ack; Removing MessageCounter:140720499 from Retrans Table on exchange 6655r I: 43133 [IM]Received status response, status is 0x00 I: 43138 [DMG]Refresh Subscribe Sync Timer with min 1 seconds and max 60 seconds I: 43146 [EM]<<< [E:6655r M:140720500 (Ack:13203505)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:04 (IM:SubscribeResponse) I: 43158 [IN](S) Sending msg 140720500 on secure session with LSID: 494 D: 43166 [DMG] OnReportConfirm: NumReports = 0 D: 43170 [DMG]IM RH moving to [GeneratingReports] D: 43175 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 43200 [EM]>>> [E:6655r M:13203506 (Ack:140720500)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 43213 [EM]Found matching exchange: 6655r, Delegate: (nil) D: 43219 [EM]Rxd Ack; Removing MessageCounter:140720500 from Retrans Table on exchange 6655r I: 43230 [EM]>>> [E:6656r M:13203507] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:08 (IM:InvokeCommandRequest) D: 43241 [EM]Handling via exchange: 6656r, Delegate: 0x2000fc3c D: 43247 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 I: 43255 [FS]GeneralCommissioning: Received CommissioningComplete I: 43329 [FP]Metadata for Fabric 0x1 persisted to storage. I: 43753 [TS]Committing Last Known Good Time to storage: 2023-02-01T06:40:32 I: 43827 [ZCL]OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0xF6C719953D1526E0, FabricId 6C804BEE3869F312, NodeId 2E660045E7AA8127, VendorId 0x110A I: 43868 [FS]GeneralCommissioning: Successfully commited pending fabric data I: 43875 [FS]Fail-safe cleanly disarmed D: 43879 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 2c2ee467 D: 43886 [DMG]Command handler moving to [ Preparing] D: 43890 [DMG]Command handler moving to [AddingComm] D: 43895 [DMG]Command handler moving to [AddedComma] D: 43900 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 43907 [EM]<<< [E:6656r M:140720501 (Ack:13203507)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:09 (IM:InvokeCommandResponse) I: 43919 [IN](S) Sending msg 140720501 on secure session with LSID: 494 D: 43928 [DMG]Command handler moving to [CommandSen] D: 43933 [DMG]Command handler moving to [AwaitingDe] I: 43937 [SWU]Device commissioned, schedule a default provider query I: 43944 [SVR]Commissioning completed successfully I: 43948 [DIS]Updating services using commissioning mode 0 D: 43953 [DL]Using Thread extended MAC for hostname. I: 43960 [DIS]Advertise operational node F6C719953D1526E0-2E660045E7AA8127 D: 43967 [DL]Using Thread extended MAC for hostname. I: 43973 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=0 D: 43984 [IN]Expiring all PASE sessions D: 43988 [IN]SecureSession[0x20003650]: MarkForEviction Type:1 LSID:493 I: 43994 [SC]SecureSession[0x20003650]: Moving from state 'kActive' --> 'kPendingEviction' D: 44002 [IN]SecureSession[0x20003650]: Released - Type:1 LSID:493 D: 44008 [IN]Clearing BLE pending packets. I: 44012 [BLE]Releasing end point's BLE connection back to application. I: 44019 [DL]Closing BLE GATT connection (ConnId 00) D: 44024 [ZCL]Commissioning complete, notify platform driver to persist network credentials. E: 44061 [DL]Long dispatch time: 124 ms, for event type 32781 I: 44067 [EM]>>> [E:6656r M:13203508 (Ack:140720501)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 44080 [EM]Found matching exchange: 6656r, Delegate: (nil) D: 44085 [EM]Rxd Ack; Removing MessageCounter:140720501 from Retrans Table on exchange 6656r I: 44094 [EM]>>> [E:6657r M:13203509] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 44105 [EM]Handling via exchange: 6657r, Delegate: 0x2000fc3c D: 44111 [IM]Received Read request D: 44115 [DMG]IM RH moving to [GeneratingReports] D: 44119 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 44128 [DMG] Cluster 31, Attribute fffc is dirty D: 44133 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) D: 44142 [DMG] Sending report (payload has 37 bytes)... I: 44148 [EM]<<< [E:6657r M:140720502 (Ack:13203509)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 44160 [IN](S) Sending msg 140720502 on secure session with LSID: 494 D: 44167 [DMG] OnReportConfirm: NumReports = 0 D: 44172 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 44180 [DMG]IM RH moving to [AwaitingDestruction] D: 44184 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 44191 [DL]BLE GAP connection terminated (reason 0x16) I: 44196 [DL]Current number of connections: 0/2 D: 44200 [DMG]Unblock report hold after min 1 seconds I: 44214 [EM]>>> [E:6657r M:13203510 (Ack:140720502)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 44227 [EM]Found matching exchange: 6657r, Delegate: (nil) D: 44232 [EM]Rxd Ack; Removing MessageCounter:140720502 from Retrans Table on exchange 6657r I: 44243 [EM]>>> [E:6658r M:13203511] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 44253 [EM]Handling via exchange: 6658r, Delegate: 0x2000fc3c D: 44259 [IM]Received Read request D: 44263 [DMG]IM RH moving to [GeneratingReports] D: 44267 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 44276 [DMG] Cluster 28, Attribute 0 is dirty D: 44281 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0000 (expanded=1) D: 44290 [DMG] Cluster 28, Attribute 1 is dirty D: 44295 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0001 (expanded=1) D: 44304 [DMG] Cluster 28, Attribute 2 is dirty D: 44309 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=1) D: 44318 [DMG] Cluster 28, Attribute 3 is dirty D: 44323 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) D: 44332 [DMG] Cluster 28, Attribute 4 is dirty D: 44337 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=1) D: 44346 [DMG] Cluster 28, Attribute 5 is dirty D: 44351 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0005 (expanded=1) D: 44360 [DMG] Cluster 28, Attribute 6 is dirty D: 44365 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0006 (expanded=1) D: 44375 [DMG] Cluster 28, Attribute 7 is dirty D: 44380 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0007 (expanded=1) D: 44390 [DMG] Cluster 28, Attribute 8 is dirty D: 44395 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0008 (expanded=1) D: 44404 [DMG] Cluster 28, Attribute 9 is dirty D: 44409 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0009 (expanded=1) D: 44418 [DMG] Cluster 28, Attribute a is dirty D: 44423 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_000A (expanded=1) D: 44432 [DMG] Cluster 28, Attribute b is dirty D: 44437 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_000B (expanded=1) D: 44447 [DMG] Cluster 28, Attribute f is dirty D: 44452 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_000F (expanded=1) D: 44462 [DMG] Cluster 28, Attribute 12 is dirty D: 44467 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0012 (expanded=1) D: 44477 [DMG] Cluster 28, Attribute 13 is dirty D: 44482 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0013 (expanded=1) D: 44491 [DMG] Cluster 28, Attribute fffc is dirty D: 44497 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 44506 [DMG] Cluster 28, Attribute fffd is dirty D: 44511 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 44520 [DMG] Cluster 28, Attribute fff8 is dirty D: 44525 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 44534 [DMG] Cluster 28, Attribute fff9 is dirty D: 44539 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 44548 [DMG] Cluster 28, Attribute fffb is dirty D: 44554 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) E: 44563 [DMG]Error retrieving data from clusterId: 0x0000_0028, err = b D: 44570 [DMG] We cannot put more chunks into this report. Enable chunking. D: 44577 [DMG] Sending report (payload has 994 bytes)... D: 44582 [DMG]IM RH moving to [AwaitingReportResponse] I: 44592 [EM]<<< [E:6658r M:140720503 (Ack:13203511)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 44603 [IN](S) Sending msg 140720503 on secure session with LSID: 494 D: 44611 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 44752 [EM]>>> [E:6658r M:13203512 (Ack:140720503)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 44764 [EM]Found matching exchange: 6658r, Delegate: 0x2001177c D: 44770 [EM]Rxd Ack; Removing MessageCounter:140720503 from Retrans Table on exchange 6658r I: 44778 [IM]Received status response, status is 0x00 D: 44783 [DMG] OnReportConfirm: NumReports = 0 D: 44788 [DMG]IM RH moving to [GeneratingReports] D: 44792 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 44801 [DMG] Cluster 28, Attribute fffb is dirty D: 44806 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 44815 [DMG] Sending report (payload has 247 bytes)... I: 44823 [EM]<<< [E:6658r M:140720504 (Ack:13203512)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 44834 [IN](S) Sending msg 140720504 on secure session with LSID: 494 D: 44841 [DMG] OnReportConfirm: NumReports = 0 D: 44846 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 44854 [DMG]IM RH moving to [AwaitingDestruction] D: 44859 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 44913 [EM]>>> [E:6658r M:13203513 (Ack:140720504)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 44926 [EM]Found matching exchange: 6658r, Delegate: (nil) D: 44931 [EM]Rxd Ack; Removing MessageCounter:140720504 from Retrans Table on exchange 6658r I: 44942 [EM]>>> [E:6659r M:13203514] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 44952 [EM]Handling via exchange: 6659r, Delegate: 0x2000fc3c D: 44958 [IM]Received Read request D: 44961 [DMG]IM RH moving to [GeneratingReports] D: 44966 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 44975 [DMG] Cluster 1d, Attribute 0 is dirty D: 44980 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0000 (expanded=1) D: 44989 [DMG] Cluster 1d, Attribute 0 is dirty D: 44994 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0000 (expanded=1) D: 45003 [DMG] Sending report (payload has 131 bytes)... I: 45009 [EM]<<< [E:6659r M:140720505 (Ack:13203514)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 45021 [IN](S) Sending msg 140720505 on secure session with LSID: 494 D: 45028 [DMG] OnReportConfirm: NumReports = 0 D: 45033 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 45041 [DMG]IM RH moving to [AwaitingDestruction] D: 45046 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 45081 [EM]>>> [E:6659r M:13203515 (Ack:140720505)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 45093 [EM]Found matching exchange: 6659r, Delegate: (nil) D: 45099 [EM]Rxd Ack; Removing MessageCounter:140720505 from Retrans Table on exchange 6659r I: 45109 [EM]>>> [E:6660r M:13203516] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 45119 [EM]Handling via exchange: 6660r, Delegate: 0x2000fc3c D: 45125 [IM]Received Read request D: 45129 [DMG]IM RH moving to [GeneratingReports] D: 45133 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 45142 [DMG] Cluster 1d, Attribute 1 is dirty D: 45147 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=1) D: 45157 [DMG] Cluster 1d, Attribute 1 is dirty D: 45162 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0001 (expanded=1) D: 45171 [DMG] Sending report (payload has 566 bytes)... I: 45179 [EM]<<< [E:6660r M:140720506 (Ack:13203516)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 45190 [IN](S) Sending msg 140720506 on secure session with LSID: 494 D: 45199 [DMG] OnReportConfirm: NumReports = 0 D: 45204 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 45211 [DMG]IM RH moving to [AwaitingDestruction] D: 45216 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 45303 [EM]>>> [E:6660r M:13203517 (Ack:140720506)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 45315 [EM]Found matching exchange: 6660r, Delegate: (nil) D: 45323 [EM]Rxd Ack; Removing MessageCounter:140720506 from Retrans Table on exchange 6660r I: 45332 [EM]>>> [E:6661r M:13203518] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 45342 [EM]Handling via exchange: 6661r, Delegate: 0x2000fc3c D: 45347 [IM]Received Read request D: 45351 [DMG]IM RH moving to [GeneratingReports] D: 45356 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 45364 [DMG] Cluster 1d, Attribute 2 is dirty D: 45370 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0002 (expanded=1) D: 45379 [DMG] Cluster 1d, Attribute 2 is dirty D: 45384 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_0002 (expanded=1) D: 45393 [DMG] Sending report (payload has 90 bytes)... I: 45399 [EM]<<< [E:6661r M:140720507 (Ack:13203518)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 45410 [IN](S) Sending msg 140720507 on secure session with LSID: 494 D: 45418 [DMG] OnReportConfirm: NumReports = 0 D: 45423 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 45431 [DMG]IM RH moving to [AwaitingDestruction] D: 45436 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 45469 [EM]>>> [E:6661r M:13203519 (Ack:140720507)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 45481 [EM]Found matching exchange: 6661r, Delegate: (nil) D: 45489 [EM]Rxd Ack; Removing MessageCounter:140720507 from Retrans Table on exchange 6661r I: 45498 [EM]>>> [E:6662r M:13203520] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 45508 [EM]Handling via exchange: 6662r, Delegate: 0x2000fc3c D: 45513 [IM]Received Read request D: 45517 [DMG]IM RH moving to [GeneratingReports] D: 45522 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 45530 [DMG] Cluster 1d, Attribute fffd is dirty D: 45536 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45545 [DMG] Cluster 1f, Attribute fffd is dirty D: 45550 [DMG]Reading attribute: Cluster=0x0000_001F Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45559 [DMG] Cluster 28, Attribute fffd is dirty D: 45564 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45573 [DMG] Cluster 2a, Attribute fffd is dirty D: 45579 [DMG]Reading attribute: Cluster=0x0000_002A Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45588 [DMG] Cluster 30, Attribute fffd is dirty D: 45593 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45602 [DMG] Cluster 31, Attribute fffd is dirty D: 45607 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45616 [DMG] Cluster 33, Attribute fffd is dirty D: 45622 [DMG]Reading attribute: Cluster=0x0000_0033 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45631 [DMG] Cluster 34, Attribute fffd is dirty D: 45636 [DMG]Reading attribute: Cluster=0x0000_0034 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45645 [DMG] Cluster 35, Attribute fffd is dirty D: 45650 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45660 [DMG] Cluster 36, Attribute fffd is dirty D: 45665 [DMG]Reading attribute: Cluster=0x0000_0036 Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45674 [DMG] Cluster 3c, Attribute fffd is dirty D: 45679 [DMG]Reading attribute: Cluster=0x0000_003C Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45688 [DMG] Cluster 3e, Attribute fffd is dirty D: 45694 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45703 [DMG] Cluster 3f, Attribute fffd is dirty D: 45708 [DMG]Reading attribute: Cluster=0x0000_003F Endpoint=0 AttributeId=0x0000_FFFD (expanded=1) D: 45717 [DMG] Cluster 3, Attribute fffd is dirty D: 45722 [DMG]Reading attribute: Cluster=0x0000_0003 Endpoint=1 AttributeId=0x0000_FFFD (expanded=1) D: 45731 [DMG] Cluster 4, Attribute fffd is dirty D: 45736 [DMG]Reading attribute: Cluster=0x0000_0004 Endpoint=1 AttributeId=0x0000_FFFD (expanded=1) D: 45745 [DMG] Cluster 6, Attribute fffd is dirty D: 45751 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFFD (expanded=1) D: 45760 [DMG] Cluster 8, Attribute fffd is dirty D: 45765 [DMG]Reading attribute: Cluster=0x0000_0008 Endpoint=1 AttributeId=0x0000_FFFD (expanded=1) D: 45774 [DMG] Cluster 1d, Attribute fffd is dirty D: 45779 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_FFFD (expanded=1) D: 45788 [DMG] Sending report (payload has 496 bytes)... I: 45796 [EM]<<< [E:6662r M:140720508 (Ack:13203520)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 45808 [IN](S) Sending msg 140720508 on secure session with LSID: 494 D: 45815 [DMG] OnReportConfirm: NumReports = 0 D: 45820 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 45828 [DMG]IM RH moving to [AwaitingDestruction] D: 45833 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 46044 [EM]>>> [E:6662r M:13203521 (Ack:140720508)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 46059 [EM]Found matching exchange: 6662r, Delegate: (nil) D: 46064 [EM]Rxd Ack; Removing MessageCounter:140720508 from Retrans Table on exchange 6662r I: 46073 [EM]>>> [E:6663r M:13203522] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 46083 [EM]Handling via exchange: 6663r, Delegate: 0x2000fc3c D: 46089 [IM]Received Read request D: 46093 [DMG]IM RH moving to [GeneratingReports] D: 46097 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 46106 [DMG] Cluster 1d, Attribute fffc is dirty D: 46111 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46120 [DMG] Cluster 1f, Attribute fffc is dirty D: 46126 [DMG]Reading attribute: Cluster=0x0000_001F Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46135 [DMG] Cluster 28, Attribute fffc is dirty D: 46140 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46149 [DMG] Cluster 2a, Attribute fffc is dirty D: 46154 [DMG]Reading attribute: Cluster=0x0000_002A Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46163 [DMG] Cluster 30, Attribute fffc is dirty D: 46169 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46178 [DMG] Cluster 31, Attribute fffc is dirty D: 46183 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46192 [DMG] Cluster 33, Attribute fffc is dirty D: 46197 [DMG]Reading attribute: Cluster=0x0000_0033 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46206 [DMG] Cluster 34, Attribute fffc is dirty D: 46212 [DMG]Reading attribute: Cluster=0x0000_0034 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46221 [DMG] Cluster 35, Attribute fffc is dirty D: 46226 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46235 [DMG] Cluster 36, Attribute fffc is dirty D: 46240 [DMG]Reading attribute: Cluster=0x0000_0036 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46249 [DMG] Cluster 3c, Attribute fffc is dirty D: 46255 [DMG]Reading attribute: Cluster=0x0000_003C Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46264 [DMG] Cluster 3e, Attribute fffc is dirty D: 46269 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46278 [DMG] Cluster 3f, Attribute fffc is dirty D: 46283 [DMG]Reading attribute: Cluster=0x0000_003F Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) D: 46292 [DMG] Cluster 3, Attribute fffc is dirty D: 46298 [DMG]Reading attribute: Cluster=0x0000_0003 Endpoint=1 AttributeId=0x0000_FFFC (expanded=1) D: 46307 [DMG] Cluster 4, Attribute fffc is dirty D: 46312 [DMG]Reading attribute: Cluster=0x0000_0004 Endpoint=1 AttributeId=0x0000_FFFC (expanded=1) D: 46321 [DMG] Cluster 6, Attribute fffc is dirty D: 46326 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFFC (expanded=1) D: 46335 [DMG] Cluster 8, Attribute fffc is dirty D: 46340 [DMG]Reading attribute: Cluster=0x0000_0008 Endpoint=1 AttributeId=0x0000_FFFC (expanded=1) D: 46350 [DMG] Cluster 1d, Attribute fffc is dirty D: 46355 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_FFFC (expanded=1) D: 46364 [DMG] Sending report (payload has 496 bytes)... I: 46372 [EM]<<< [E:6663r M:140720509 (Ack:13203522)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 46383 [IN](S) Sending msg 140720509 on secure session with LSID: 494 D: 46391 [DMG] OnReportConfirm: NumReports = 0 D: 46396 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 46404 [DMG]IM RH moving to [AwaitingDestruction] D: 46409 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 46572 [EM]>>> [E:6663r M:13203523 (Ack:140720509)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 46585 [EM]Found matching exchange: 6663r, Delegate: (nil) D: 46592 [EM]Rxd Ack; Removing MessageCounter:140720509 from Retrans Table on exchange 6663r I: 46601 [EM]>>> [E:6664r M:13203524] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 46611 [EM]Handling via exchange: 6664r, Delegate: 0x2000fc3c D: 46616 [IM]Received Read request D: 46620 [DMG]IM RH moving to [GeneratingReports] D: 46625 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 46633 [DMG] Cluster 1d, Attribute fffb is dirty D: 46639 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 46648 [DMG] Cluster 1f, Attribute fffb is dirty D: 46653 [DMG]Reading attribute: Cluster=0x0000_001F Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 46663 [DMG] Cluster 28, Attribute fffb is dirty D: 46668 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) E: 46678 [DMG]Error retrieving data from clusterId: 0x0000_0028, err = b D: 46684 [DMG] We cannot put more chunks into this report. Enable chunking. D: 46691 [DMG] Sending report (payload has 1000 bytes)... D: 46697 [DMG]IM RH moving to [AwaitingReportResponse] I: 46707 [EM]<<< [E:6664r M:140720510 (Ack:13203524)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 46718 [IN](S) Sending msg 140720510 on secure session with LSID: 494 D: 46726 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 46943 [EM]>>> [E:6664r M:13203525 (Ack:140720510)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 46955 [EM]Found matching exchange: 6664r, Delegate: 0x2001177c D: 46960 [EM]Rxd Ack; Removing MessageCounter:140720510 from Retrans Table on exchange 6664r I: 46969 [IM]Received status response, status is 0x00 D: 46974 [DMG] OnReportConfirm: NumReports = 0 D: 46978 [DMG]IM RH moving to [GeneratingReports] D: 46983 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 46991 [DMG] Cluster 28, Attribute fffb is dirty D: 46997 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 47006 [DMG] Cluster 2a, Attribute fffb is dirty D: 47011 [DMG]Reading attribute: Cluster=0x0000_002A Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 47020 [DMG] Cluster 30, Attribute fffb is dirty D: 47026 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 47035 [DMG] Cluster 31, Attribute fffb is dirty D: 47041 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) E: 47050 [DMG]Error retrieving data from clusterId: 0x0000_0031, err = b D: 47056 [DMG] We cannot put more chunks into this report. Enable chunking. D: 47064 [DMG] Sending report (payload has 1005 bytes)... D: 47069 [DMG]IM RH moving to [AwaitingReportResponse] I: 47079 [EM]<<< [E:6664r M:140720511 (Ack:13203525)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 47090 [IN](S) Sending msg 140720511 on secure session with LSID: 494 D: 47098 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 47306 [EM]>>> [E:6664r M:13203526 (Ack:140720511)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 47318 [EM]Found matching exchange: 6664r, Delegate: 0x2001177c D: 47324 [EM]Rxd Ack; Removing MessageCounter:140720511 from Retrans Table on exchange 6664r I: 47332 [IM]Received status response, status is 0x00 D: 47337 [DMG] OnReportConfirm: NumReports = 0 D: 47341 [DMG]IM RH moving to [GeneratingReports] D: 47346 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 47355 [DMG] Cluster 31, Attribute fffb is dirty D: 47360 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 47369 [DMG] Cluster 33, Attribute fffb is dirty D: 47375 [DMG]Reading attribute: Cluster=0x0000_0033 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 47384 [DMG] Cluster 34, Attribute fffb is dirty D: 47389 [DMG]Reading attribute: Cluster=0x0000_0034 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 47399 [DMG] Cluster 35, Attribute fffb is dirty D: 47404 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) E: 47413 [DMG]Error retrieving data from clusterId: 0x0000_0035, err = b D: 47419 [DMG] We cannot put more chunks into this report. Enable chunking. D: 47427 [DMG] Sending report (payload has 1005 bytes)... D: 47432 [DMG]IM RH moving to [AwaitingReportResponse] I: 47442 [EM]<<< [E:6664r M:140720512 (Ack:13203526)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 47453 [IN](S) Sending msg 140720512 on secure session with LSID: 494 D: 47461 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 47667 [EM]>>> [E:6664r M:13203527 (Ack:140720512)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 47678 [EM]Found matching exchange: 6664r, Delegate: 0x2001177c D: 47684 [EM]Rxd Ack; Removing MessageCounter:140720512 from Retrans Table on exchange 6664r I: 47692 [IM]Received status response, status is 0x00 D: 47697 [DMG] OnReportConfirm: NumReports = 0 D: 47702 [DMG]IM RH moving to [GeneratingReports] D: 47706 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 47715 [DMG] Cluster 35, Attribute fffb is dirty D: 47720 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) E: 47731 [DMG]Error retrieving data from clusterId: 0x0000_0035, err = b D: 47737 [DMG] We cannot put more chunks into this report. Enable chunking. D: 47744 [DMG] Sending report (payload has 996 bytes)... D: 47750 [DMG]IM RH moving to [AwaitingReportResponse] I: 47760 [EM]<<< [E:6664r M:140720513 (Ack:13203527)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 47771 [IN](S) Sending msg 140720513 on secure session with LSID: 494 D: 47779 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 47985 [EM]>>> [E:6664r M:13203528 (Ack:140720513)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 47996 [EM]Found matching exchange: 6664r, Delegate: 0x2001177c D: 48002 [EM]Rxd Ack; Removing MessageCounter:140720513 from Retrans Table on exchange 6664r I: 48010 [IM]Received status response, status is 0x00 D: 48015 [DMG] OnReportConfirm: NumReports = 0 D: 48020 [DMG]IM RH moving to [GeneratingReports] D: 48024 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48033 [DMG] Cluster 35, Attribute fffb is dirty D: 48038 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 48048 [DMG] Cluster 36, Attribute fffb is dirty D: 48054 [DMG]Reading attribute: Cluster=0x0000_0036 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) E: 48063 [DMG]Error retrieving data from clusterId: 0x0000_0036, err = b D: 48069 [DMG] We cannot put more chunks into this report. Enable chunking. D: 48077 [DMG] Sending report (payload has 999 bytes)... D: 48082 [DMG]IM RH moving to [AwaitingReportResponse] I: 48092 [EM]<<< [E:6664r M:140720514 (Ack:13203528)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 48103 [IN](S) Sending msg 140720514 on secure session with LSID: 494 D: 48111 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 48305 [EM]>>> [E:6664r M:13203529 (Ack:140720514)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 48317 [EM]Found matching exchange: 6664r, Delegate: 0x2001177c D: 48323 [EM]Rxd Ack; Removing MessageCounter:140720514 from Retrans Table on exchange 6664r I: 48332 [IM]Received status response, status is 0x00 D: 48336 [DMG] OnReportConfirm: NumReports = 0 D: 48341 [DMG]IM RH moving to [GeneratingReports] D: 48346 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48354 [DMG] Cluster 36, Attribute fffb is dirty D: 48360 [DMG]Reading attribute: Cluster=0x0000_0036 Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 48369 [DMG] Cluster 3c, Attribute fffb is dirty D: 48375 [DMG]Reading attribute: Cluster=0x0000_003C Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 48384 [DMG] Cluster 3e, Attribute fffb is dirty D: 48389 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) E: 48398 [DMG]Error retrieving data from clusterId: 0x0000_003E, err = b D: 48405 [DMG] We cannot put more chunks into this report. Enable chunking. D: 48412 [DMG] Sending report (payload has 1005 bytes)... D: 48418 [DMG]IM RH moving to [AwaitingReportResponse] I: 48428 [EM]<<< [E:6664r M:140720515 (Ack:13203529)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 48439 [IN](S) Sending msg 140720515 on secure session with LSID: 494 D: 48447 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 48600 [EM]>>> [E:6664r M:13203530 (Ack:140720515)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 48612 [EM]Found matching exchange: 6664r, Delegate: 0x2001177c D: 48618 [EM]Rxd Ack; Removing MessageCounter:140720515 from Retrans Table on exchange 6664r I: 48626 [IM]Received status response, status is 0x00 D: 48631 [DMG] OnReportConfirm: NumReports = 0 D: 48636 [DMG]IM RH moving to [GeneratingReports] D: 48640 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48649 [DMG] Cluster 3e, Attribute fffb is dirty D: 48654 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 48663 [DMG] Cluster 3f, Attribute fffb is dirty D: 48668 [DMG]Reading attribute: Cluster=0x0000_003F Endpoint=0 AttributeId=0x0000_FFFB (expanded=1) D: 48678 [DMG] Cluster 3, Attribute fffb is dirty D: 48683 [DMG]Reading attribute: Cluster=0x0000_0003 Endpoint=1 AttributeId=0x0000_FFFB (expanded=1) D: 48692 [DMG] Cluster 4, Attribute fffb is dirty D: 48697 [DMG]Reading attribute: Cluster=0x0000_0004 Endpoint=1 AttributeId=0x0000_FFFB (expanded=1) D: 48707 [DMG] Cluster 6, Attribute fffb is dirty D: 48712 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFFB (expanded=1) E: 48721 [DMG]Error retrieving data from clusterId: 0x0000_0006, err = b D: 48728 [DMG] We cannot put more chunks into this report. Enable chunking. D: 48735 [DMG] Sending report (payload has 980 bytes)... D: 48740 [DMG]IM RH moving to [AwaitingReportResponse] I: 48750 [EM]<<< [E:6664r M:140720516 (Ack:13203530)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 48761 [IN](S) Sending msg 140720516 on secure session with LSID: 494 D: 48769 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 48915 [EM]>>> [E:6664r M:13203531 (Ack:140720516)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 48927 [EM]Found matching exchange: 6664r, Delegate: 0x2001177c D: 48932 [EM]Rxd Ack; Removing MessageCounter:140720516 from Retrans Table on exchange 6664r I: 48941 [IM]Received status response, status is 0x00 D: 48946 [DMG] OnReportConfirm: NumReports = 0 D: 48950 [DMG]IM RH moving to [GeneratingReports] D: 48955 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 48963 [DMG] Cluster 6, Attribute fffb is dirty D: 48968 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFFB (expanded=1) D: 48978 [DMG] Cluster 8, Attribute fffb is dirty D: 48983 [DMG]Reading attribute: Cluster=0x0000_0008 Endpoint=1 AttributeId=0x0000_FFFB (expanded=1) D: 48992 [DMG] Cluster 1d, Attribute fffb is dirty D: 48998 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_FFFB (expanded=1) D: 49007 [DMG] Sending report (payload has 950 bytes)... I: 49017 [EM]<<< [E:6664r M:140720517 (Ack:13203531)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 49028 [IN](S) Sending msg 140720517 on secure session with LSID: 494 D: 49037 [DMG] OnReportConfirm: NumReports = 0 D: 49042 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 49050 [DMG]IM RH moving to [AwaitingDestruction] D: 49054 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 49176 [EM]>>> [E:6664r M:13203532 (Ack:140720517)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 49189 [EM]Found matching exchange: 6664r, Delegate: (nil) D: 49194 [EM]Rxd Ack; Removing MessageCounter:140720517 from Retrans Table on exchange 6664r I: 49205 [EM]>>> [E:6665r M:13203533] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 49215 [EM]Handling via exchange: 6665r, Delegate: 0x2000fc3c D: 49221 [IM]Received Read request D: 49224 [DMG]IM RH moving to [GeneratingReports] D: 49229 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 49238 [DMG] Cluster 1d, Attribute fff9 is dirty D: 49243 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49252 [DMG] Cluster 1f, Attribute fff9 is dirty D: 49257 [DMG]Reading attribute: Cluster=0x0000_001F Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49266 [DMG] Cluster 28, Attribute fff9 is dirty D: 49272 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49281 [DMG] Cluster 2a, Attribute fff9 is dirty D: 49286 [DMG]Reading attribute: Cluster=0x0000_002A Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49295 [DMG] Cluster 30, Attribute fff9 is dirty D: 49300 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49309 [DMG] Cluster 31, Attribute fff9 is dirty D: 49315 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49324 [DMG] Cluster 33, Attribute fff9 is dirty D: 49329 [DMG]Reading attribute: Cluster=0x0000_0033 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49338 [DMG] Cluster 34, Attribute fff9 is dirty D: 49344 [DMG]Reading attribute: Cluster=0x0000_0034 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49353 [DMG] Cluster 35, Attribute fff9 is dirty D: 49358 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49367 [DMG] Cluster 36, Attribute fff9 is dirty D: 49372 [DMG]Reading attribute: Cluster=0x0000_0036 Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49381 [DMG] Cluster 3c, Attribute fff9 is dirty D: 49387 [DMG]Reading attribute: Cluster=0x0000_003C Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49396 [DMG] Cluster 3e, Attribute fff9 is dirty D: 49401 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49411 [DMG] Cluster 3f, Attribute fff9 is dirty D: 49416 [DMG]Reading attribute: Cluster=0x0000_003F Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) E: 49425 [DMG]Error retrieving data from clusterId: 0x0000_003F, err = b D: 49431 [DMG] We cannot put more chunks into this report. Enable chunking. D: 49439 [DMG] Sending report (payload has 1001 bytes)... D: 49444 [DMG]IM RH moving to [AwaitingReportResponse] I: 49454 [EM]<<< [E:6665r M:140720518 (Ack:13203533)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 49465 [IN](S) Sending msg 140720518 on secure session with LSID: 494 D: 49473 [DMG] ReportsInFlight = 1 with readHandler 1, RE has more messages I: 49619 [EM]>>> [E:6665r M:13203534 (Ack:140720518)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 49631 [EM]Found matching exchange: 6665r, Delegate: 0x2001177c D: 49637 [EM]Rxd Ack; Removing MessageCounter:140720518 from Retrans Table on exchange 6665r I: 49645 [IM]Received status response, status is 0x00 D: 49650 [DMG] OnReportConfirm: NumReports = 0 D: 49655 [DMG]IM RH moving to [GeneratingReports] D: 49659 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 49668 [DMG] Cluster 3f, Attribute fff9 is dirty D: 49673 [DMG]Reading attribute: Cluster=0x0000_003F Endpoint=0 AttributeId=0x0000_FFF9 (expanded=1) D: 49682 [DMG] Cluster 3, Attribute fff9 is dirty D: 49687 [DMG]Reading attribute: Cluster=0x0000_0003 Endpoint=1 AttributeId=0x0000_FFF9 (expanded=1) D: 49697 [DMG] Cluster 4, Attribute fff9 is dirty D: 49702 [DMG]Reading attribute: Cluster=0x0000_0004 Endpoint=1 AttributeId=0x0000_FFF9 (expanded=1) D: 49711 [DMG] Cluster 6, Attribute fff9 is dirty D: 49716 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFF9 (expanded=1) D: 49725 [DMG] Cluster 8, Attribute fff9 is dirty D: 49731 [DMG]Reading attribute: Cluster=0x0000_0008 Endpoint=1 AttributeId=0x0000_FFF9 (expanded=1) D: 49740 [DMG] Cluster 1d, Attribute fff9 is dirty D: 49745 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_FFF9 (expanded=1) D: 49754 [DMG] Sending report (payload has 926 bytes)... I: 49764 [EM]<<< [E:6665r M:140720519 (Ack:13203534)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 49775 [IN](S) Sending msg 140720519 on secure session with LSID: 494 D: 49783 [DMG] OnReportConfirm: NumReports = 0 D: 49788 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 49796 [DMG]IM RH moving to [AwaitingDestruction] D: 49801 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 49925 [EM]>>> [E:6665r M:13203535 (Ack:140720519)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 49938 [EM]Found matching exchange: 6665r, Delegate: (nil) D: 49943 [EM]Rxd Ack; Removing MessageCounter:140720519 from Retrans Table on exchange 6665r I: 49954 [EM]>>> [E:6666r M:13203536] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 49964 [EM]Handling via exchange: 6666r, Delegate: 0x2000fc3c D: 49970 [IM]Received Read request D: 49973 [DMG]IM RH moving to [GeneratingReports] D: 49978 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 49987 [DMG] Cluster 1d, Attribute fff8 is dirty D: 49992 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50001 [DMG] Cluster 1f, Attribute fff8 is dirty D: 50006 [DMG]Reading attribute: Cluster=0x0000_001F Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50015 [DMG] Cluster 28, Attribute fff8 is dirty D: 50021 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50030 [DMG] Cluster 2a, Attribute fff8 is dirty D: 50035 [DMG]Reading attribute: Cluster=0x0000_002A Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50044 [DMG] Cluster 30, Attribute fff8 is dirty D: 50049 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50058 [DMG] Cluster 31, Attribute fff8 is dirty D: 50064 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50073 [DMG] Cluster 33, Attribute fff8 is dirty D: 50078 [DMG]Reading attribute: Cluster=0x0000_0033 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50087 [DMG] Cluster 34, Attribute fff8 is dirty D: 50092 [DMG]Reading attribute: Cluster=0x0000_0034 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50101 [DMG] Cluster 35, Attribute fff8 is dirty D: 50107 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50116 [DMG] Cluster 36, Attribute fff8 is dirty D: 50121 [DMG]Reading attribute: Cluster=0x0000_0036 Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50130 [DMG] Cluster 3c, Attribute fff8 is dirty D: 50135 [DMG]Reading attribute: Cluster=0x0000_003C Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50144 [DMG] Cluster 3e, Attribute fff8 is dirty D: 50150 [DMG]Reading attribute: Cluster=0x0000_003E Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50159 [DMG] Cluster 3f, Attribute fff8 is dirty D: 50164 [DMG]Reading attribute: Cluster=0x0000_003F Endpoint=0 AttributeId=0x0000_FFF8 (expanded=1) D: 50173 [DMG] Cluster 3, Attribute fff8 is dirty D: 50178 [DMG]Reading attribute: Cluster=0x0000_0003 Endpoint=1 AttributeId=0x0000_FFF8 (expanded=1) D: 50187 [DMG] Cluster 4, Attribute fff8 is dirty D: 50193 [DMG]Reading attribute: Cluster=0x0000_0004 Endpoint=1 AttributeId=0x0000_FFF8 (expanded=1) D: 50202 [DMG] Cluster 6, Attribute fff8 is dirty D: 50207 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_FFF8 (expanded=1) D: 50216 [DMG] Cluster 8, Attribute fff8 is dirty D: 50221 [DMG]Reading attribute: Cluster=0x0000_0008 Endpoint=1 AttributeId=0x0000_FFF8 (expanded=1) D: 50230 [DMG] Cluster 1d, Attribute fff8 is dirty D: 50236 [DMG]Reading attribute: Cluster=0x0000_001D Endpoint=1 AttributeId=0x0000_FFF8 (expanded=1) D: 50245 [DMG] Sending report (payload has 960 bytes)... I: 50255 [EM]<<< [E:6666r M:140720520 (Ack:13203536)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 50266 [IN](S) Sending msg 140720520 on secure session with LSID: 494 D: 50274 [DMG] OnReportConfirm: NumReports = 0 D: 50279 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 50287 [DMG]IM RH moving to [AwaitingDestruction] D: 50291 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 50422 [EM]>>> [E:6666r M:13203537 (Ack:140720520)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 50435 [EM]Found matching exchange: 6666r, Delegate: (nil) D: 50440 [EM]Rxd Ack; Removing MessageCounter:140720520 from Retrans Table on exchange 6666r I: 50451 [EM]>>> [E:6667r M:13203538] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 50461 [EM]Handling via exchange: 6667r, Delegate: 0x2000fc3c D: 50467 [IM]Received Read request D: 50471 [DMG]IM RH moving to [GeneratingReports] D: 50475 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 50484 [DMG] Sending report (payload has 7 bytes)... I: 50490 [EM]<<< [E:6667r M:140720521 (Ack:13203538)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 50501 [IN](S) Sending msg 140720521 on secure session with LSID: 494 D: 50509 [DMG] OnReportConfirm: NumReports = 0 D: 50514 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 50521 [DMG]IM RH moving to [AwaitingDestruction] D: 50526 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 50546 [EM]>>> [E:6667r M:13203539 (Ack:140720521)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 50559 [EM]Found matching exchange: 6667r, Delegate: (nil) D: 50566 [EM]Rxd Ack; Removing MessageCounter:140720521 from Retrans Table on exchange 6667r I: 50575 [EM]>>> [E:6668r M:13203540] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:02 (IM:ReadRequest) D: 50585 [EM]Handling via exchange: 6668r, Delegate: 0x2000fc3c D: 50591 [IM]Received Read request D: 50595 [DMG]IM RH moving to [GeneratingReports] D: 50599 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 50608 [DMG] Cluster 35, Attribute 1 is dirty D: 50613 [DMG]Reading attribute: Cluster=0x0000_0035 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) D: 50622 [DMG] Sending report (payload has 36 bytes)... I: 50628 [EM]<<< [E:6668r M:140720522 (Ack:13203540)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 50639 [IN](S) Sending msg 140720522 on secure session with LSID: 494 D: 50647 [DMG] OnReportConfirm: NumReports = 0 D: 50651 [DMG] ReportsInFlight = 0 with readHandler 1, RE has no more messages D: 50659 [DMG]IM RH moving to [AwaitingDestruction] D: 50664 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 50691 [EM]>>> [E:6668r M:13203541 (Ack:140720522)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 50705 [EM]Found matching exchange: 6668r, Delegate: (nil) D: 50710 [EM]Rxd Ack; Removing MessageCounter:140720522 from Retrans Table on exchange 6668r I: 50721 [EM]>>> [E:6669r M:13203542] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:08 (IM:InvokeCommandRequest) D: 50732 [EM]Handling via exchange: 6669r, Delegate: 0x2000fc3c D: 50738 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0009 I: 50746 [ZCL]OpCreds: Received an UpdateFabricLabel command I: 50776 [FP]Metadata for Fabric 0x1 persisted to storage. D: 50781 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 304df8d0 D: 50787 [DMG]Command handler moving to [ Preparing] D: 50792 [DMG]Command handler moving to [AddingComm] D: 50797 [DMG]Command handler moving to [AddedComma] D: 50802 [DMG]Decreasing reference count for CommandHandler, remaining 0 I: 50809 [EM]<<< [E:6669r M:140720523 (Ack:13203542)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:09 (IM:InvokeCommandResponse) I: 50821 [IN](S) Sending msg 140720523 on secure session with LSID: 494 D: 50829 [DMG]Command handler moving to [CommandSen] D: 50834 [DMG]Command handler moving to [AwaitingDe] I: 50867 [EM]>>> [E:6669r M:13203543 (Ack:140720523)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 50879 [EM]Found matching exchange: 6669r, Delegate: (nil) D: 50885 [EM]Rxd Ack; Removing MessageCounter:140720523 from Retrans Table on exchange 6669r I: 52269 [EM]>>> [E:6670r M:13203544] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:06 (IM:WriteRequest) D: 52279 [EM]Handling via exchange: 6670r, Delegate: 0x2000fc3c D: 52285 [IM]Received Write request D: 52288 [DMG]IM WH moving to [Initialized] D: 52341 [DMG]Endpoint 0, Cluster 0x0000_0028 update version to 993312c4 D: 52348 [DMG]IM WH moving to [AddStatus] I: 52352 [EM]<<< [E:6670r M:140720524 (Ack:13203544)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:07 (IM:WriteResponse) I: 52364 [IN](S) Sending msg 140720524 on secure session with LSID: 494 D: 52372 [DMG]IM WH moving to [Sending] D: 52375 [DMG]IM WH moving to [Uninitialized] I: 52400 [EM]>>> [E:6670r M:13203545 (Ack:140720524)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 52413 [EM]Found matching exchange: 6670r, Delegate: (nil) D: 52418 [EM]Rxd Ack; Removing MessageCounter:140720524 from Retrans Table on exchange 6670r I: 52993 [EM]>>> [E:6671r M:13203546] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:03 (IM:SubscribeRequest) D: 53004 [EM]Handling via exchange: 6671r, Delegate: 0x2000fc3c D: 53010 [IM]Received Subscribe request I: 53013 [IM]Deleting previous subscription from NodeId: 4EDF6C6116ACADD8, FabricIndex: 1 I: 53023 [DMG]Final negotiated min/max parameters: Min = 1s, Max = 30s D: 53029 [DMG]IM RH moving to [GeneratingReports] D: 53034 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 D: 53042 [DMG] Cluster 8, Attribute 0 is dirty D: 53047 [DMG]Reading attribute: Cluster=0x0000_0008 Endpoint=1 AttributeId=0x0000_0000 (expanded=1) D: 53056 [DMG] Cluster 6, Attribute 0 is dirty D: 53061 [DMG]Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_0000 (expanded=1) D: 53070 [DMG] Sending report (payload has 65 bytes)... D: 53076 [DMG]IM RH moving to [AwaitingReportResponse] I: 53081 [EM]<<< [E:6671r M:140720525 (Ack:13203546)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 53093 [IN](S) Sending msg 140720525 on secure session with LSID: 494 D: 53100 [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages D: 53108 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 53150 [EM]>>> [E:6671r M:13203547 (Ack:140720525)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 53161 [EM]Found matching exchange: 6671r, Delegate: 0x200116e4 D: 53167 [EM]Rxd Ack; Removing MessageCounter:140720525 from Retrans Table on exchange 6671r I: 53176 [IM]Received status response, status is 0x00 I: 53181 [DMG]Refresh Subscribe Sync Timer with min 1 seconds and max 30 seconds I: 53188 [EM]<<< [E:6671r M:140720526 (Ack:13203547)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:04 (IM:SubscribeResponse) I: 53200 [IN](S) Sending msg 140720526 on secure session with LSID: 494 D: 53208 [DMG] OnReportConfirm: NumReports = 0 D: 53213 [DMG]IM RH moving to [GeneratingReports] D: 53217 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 53244 [EM]>>> [E:6671r M:13203548 (Ack:140720526)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) D: 53256 [EM]Found matching exchange: 6671r, Delegate: (nil) D: 53262 [EM]Rxd Ack; Removing MessageCounter:140720526 from Retrans Table on exchange 6671r D: 54188 [DMG]Unblock report hold after min 1 seconds E: 73943 [SWU]No suitable OTA Provider candidate found I: 73948 [SWU]No provider available I: 83193 [DMG]Refresh subscribe timer sync after 29 seconds D: 83199 [DMG]Building Reports for ReadHandler with LastReportGeneration = 22 DirtyGeneration = 0 D: 83208 [DMG] Sending report (payload has 11 bytes)... D: 83213 [DMG]IM RH moving to [AwaitingReportResponse] I: 83218 [EM]<<< [E:41279i M:140720527] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 83228 [IN](S) Sending msg 140720527 on secure session with LSID: 494 I: 83236 [DMG]Refresh Subscribe Sync Timer with min 1 seconds and max 30 seconds D: 83243 [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages D: 83251 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 83272 [EM]>>> [E:41279i M:13203549 (Ack:140720527)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 83284 [EM]Found matching exchange: 41279i, Delegate: 0x200116e4 D: 83290 [EM]Rxd Ack; Removing MessageCounter:140720527 from Retrans Table on exchange 41279i I: 83298 [IM]Received status response, status is 0x00 D: 83303 [DMG] OnReportConfirm: NumReports = 0 D: 83307 [DMG]IM RH moving to [GeneratingReports] I: 83312 [EM]<<< [E:41279i M:140720528 (Ack:13203549)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 83325 [IN](S) Sending msg 140720528 on secure session with LSID: 494 D: 83332 [EM]Flushed pending ack for MessageCounter:13203549 on exchange 41279i D: 83340 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 84243 [DMG]Unblock report hold after min 1 seconds I: 113248 [DMG]Refresh subscribe timer sync after 29 seconds D: 113254 [DMG]Building Reports for ReadHandler with LastReportGeneration = 22 DirtyGeneration = 0 D: 113262 [DMG] Sending report (payload has 11 bytes)... D: 113268 [DMG]IM RH moving to [AwaitingReportResponse] I: 113274 [EM]<<< [E:41280i M:140720529] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:05 (IM:ReportData) I: 113284 [IN](S) Sending msg 140720529 on secure session with LSID: 494 I: 113291 [DMG]Refresh Subscribe Sync Timer with min 1 seconds and max 30 seconds D: 113299 [DMG] ReportsInFlight = 1 with readHandler 0, RE has no more messages D: 113307 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet I: 113325 [EM]>>> [E:41280i M:13203550 (Ack:140720529)] (S) Msg RX from 1:4EDF6C6116ACADD8 [26E0] --- Type 0001:01 (IM:StatusResponse) D: 113337 [EM]Found matching exchange: 41280i, Delegate: 0x200116e4 D: 113343 [EM]Rxd Ack; Removing MessageCounter:140720529 from Retrans Table on exchange 41280i I: 113352 [IM]Received status response, status is 0x00 D: 113356 [DMG] OnReportConfirm: NumReports = 0 D: 113361 [DMG]IM RH moving to [GeneratingReports] I: 113366 [EM]<<< [E:41280i M:140720530 (Ack:13203550)] (S) Msg TX to 1:4EDF6C6116ACADD8 [26E0] --- Type 0000:10 (SecureChannel:StandaloneAck) I: 113379 [IN](S) Sending msg 140720530 on secure session with LSID: 494 D: 113386 [EM]Flushed pending ack for MessageCounter:13203550 on exchange 41280i D: 113394 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet D: 114299 [DMG]Unblock report hold after min 1 seconds