Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Logging] Log the duration for successfully establishing a subscription #36115

Merged

Conversation

vivien-apple
Copy link
Contributor

Problem

Right now, there’s no way to see how long it actually takes to set up a subscription just by looking at the logs.
This makes it a bit tough for anyone relying on logging (and not a full tracing system) to get a sense of timing when subscriptions are established.
Having some basic timing info would be helpful, especially when debugging performance or responsiveness issues.

This PR log the time taken once the subscription is confirmed, available only when progress logging is enabled.

@vivien-apple vivien-apple self-assigned this Oct 17, 2024
Copy link

Review changes with SemanticDiff.

Copy link

github-actions bot commented Oct 17, 2024

PR #36115: Size comparison from 150db87 to c189648

Full report (20 builds for cc13x4_26x4, cc32xx, nrfconnect, nxp, qpg, stm32, tizen)
platform target config section 150db87 c189648 change % change
cc13x4_26x4 lighting-app LP_EM_CC1354P10_6 FLASH 829564 829564 0 0.0
RAM 123452 123452 0 0.0
lock-ftd LP_EM_CC1354P10_6 FLASH 814872 814872 0 0.0
RAM 125332 125332 0 0.0
pump-app LP_EM_CC1354P10_6 FLASH 761420 761460 40 0.0
RAM 113824 113824 0 0.0
pump-controller-app LP_EM_CC1354P10_6 FLASH 745664 745704 40 0.0
RAM 114016 114016 0 0.0
cc32xx air-purifier CC3235SF_LAUNCHXL FLASH 617202 617226 24 0.0
RAM 205908 205908 0 0.0
lock CC3235SF_LAUNCHXL FLASH 657258 657282 24 0.0
RAM 206060 206060 0 0.0
nrfconnect all-clusters-app nrf52840dk_nrf52840 FLASH 915512 915604 92 0.0
RAM 143359 143359 0 0.0
nrf7002dk_nrf5340_cpuapp FLASH 886016 886016 0 0.0
RAM 141498 141498 0 0.0
all-clusters-minimal-app nrf52840dk_nrf52840 FLASH 848932 848932 0 0.0
RAM 142261 142261 0 0.0
nxp contact k32w1+release FLASH 597136 597176 40 0.0
RAM 63184 63184 0 0.0
mcxw71+release FLASH 596896 596936 40 0.0
RAM 63184 63184 0 0.0
light k32w1+release FLASH 683112 683160 48 0.0
RAM 48816 48816 0 0.0
mcxw71+release FLASH 683128 683176 48 0.0
RAM 48816 48816 0 0.0
lock k32w1+release FLASH 705480 705528 48 0.0
RAM 67324 67324 0 0.0
mcxw71+release FLASH 705504 705552 48 0.0
RAM 67324 67324 0 0.0
qpg lighting-app qpg6105+debug FLASH 660560 660608 48 0.0
RAM 105396 105396 0 0.0
lock-app qpg6105+debug FLASH 618580 618620 40 0.0
RAM 99864 99864 0 0.0
stm32 light STM32WB5MM-DK FLASH 481896 481944 48 0.0
RAM 144844 144844 0 0.0
tizen all-clusters-app arm unknown 4912 4912 0 0.0
FLASH 1729220 1729424 204 0.0
RAM 90180 90180 0 0.0
chip-tool-ubsan arm unknown 10792 10792 0 0.0
FLASH 18327198 18327598 400 0.0
RAM 7969512 7969872 360 0.0

@vivien-apple vivien-apple force-pushed the Logging_SubscriptionEstablished branch from c189648 to ae37268 Compare October 17, 2024 10:07
Copy link

github-actions bot commented Oct 17, 2024

PR #36115: Size comparison from 150db87 to ae37268

Full report (39 builds for linux, nrfconnect, stm32, telink, tizen)
platform target config section 150db87 ae37268 change % change
linux air-purifier-app debug unknown 4688 4688 0 0.0
FLASH 2781089 2781155 66 0.0
RAM 129520 129520 0 0.0
all-clusters-app debug unknown 5528 5528 0 0.0
FLASH 6092068 6092278 210 0.0
RAM 524128 524128 0 0.0
all-clusters-minimal-app debug unknown 5424 5424 0 0.0
FLASH 5422820 5422854 34 0.0
RAM 242416 242416 0 0.0
bridge-app debug unknown 5408 5408 0 0.0
FLASH 4751720 4751754 34 0.0
RAM 218384 218384 0 0.0
chip-tool debug unknown 5960 5960 0 0.0
FLASH 13161544 13161786 242 0.0
RAM 584562 584562 0 0.0
chip-tool-ipv6only arm64 unknown 21408 21408 0 0.0
FLASH 11720160 11720288 128 0.0
RAM 635480 635480 0 0.0
fabric-admin debug unknown 5792 5792 0 0.0
FLASH 11380187 11380397 210 0.0
RAM 584458 584458 0 0.0
fabric-bridge-app debug unknown 4632 4632 0 0.0
FLASH 4575352 4575386 34 0.0
RAM 205048 205048 0 0.0
lighting-app debug+rpc+ui unknown 6056 6056 0 0.0
FLASH 5693713 5693713 0 0.0
RAM 228488 228488 0 0.0
lock-app debug unknown 5344 5344 0 0.0
FLASH 4801296 4801330 34 0.0
RAM 204472 204472 0 0.0
ota-provider-app debug unknown 4720 4720 0 0.0
FLASH 4430678 4430712 34 0.0
RAM 198192 198192 0 0.0
ota-requestor-app debug unknown 4656 4656 0 0.0
FLASH 4569444 4569478 34 0.0
RAM 202760 202760 0 0.0
shell debug unknown 4216 4216 0 0.0
FLASH 3115549 3115789 240 0.0
RAM 160496 160496 0 0.0
thermostat-no-ble arm64 unknown 9448 9448 0 0.0
FLASH 4319696 4319728 32 0.0
RAM 242888 242888 0 0.0
tv-app debug unknown 5624 5624 0 0.0
FLASH 6031557 6031765 208 0.0
RAM 596416 596416 0 0.0
tv-casting-app debug unknown 5208 5208 0 0.0
FLASH 11367389 11367597 208 0.0
RAM 675936 675936 0 0.0
nrfconnect all-clusters-app nrf52840dk_nrf52840 FLASH 915512 915596 84 0.0
RAM 143359 143359 0 0.0
nrf7002dk_nrf5340_cpuapp FLASH 886016 886016 0 0.0
RAM 141498 141498 0 0.0
all-clusters-minimal-app nrf52840dk_nrf52840 FLASH 848932 848932 0 0.0
RAM 142261 142261 0 0.0
stm32 light STM32WB5MM-DK FLASH 481896 481944 48 0.0
RAM 144844 144844 0 0.0
telink air-quality-sensor-app tlsr9528a_retention FLASH 620998 621048 50 0.0
RAM 50648 50648 0 0.0
all-clusters-app tlsr9118bdk40d FLASH 689376 689452 76 0.0
RAM 149488 149488 0 0.0
all-clusters-minimal-app tlsr9528a FLASH 782368 782418 50 0.0
RAM 111440 111440 0 0.0
bridge-app tlsr9258a FLASH 681098 681148 50 0.0
RAM 91304 91304 0 0.0
contact-sensor-app tlsr9528a_retention FLASH 620762 620812 50 0.0
RAM 50600 50600 0 0.0
light-switch-app-ota-shell-factory-data tlsr9528a FLASH 708716 708792 76 0.0
RAM 73940 73940 0 0.0
lighting-app-ota-factory-data tlsr9118bdk40d FLASH 625712 625762 50 0.0
RAM 144468 144468 0 0.0
lighting-app-ota-rpc-factory-data-4mb tlsr9518adk80d FLASH 811720 811770 50 0.0
RAM 99100 99100 0 0.0
lock-app-dfu tlsr9528a FLASH 656668 656718 50 0.0
RAM 66660 66660 0 0.0
ota-requestor-app tlsr9258a FLASH 697076 697126 50 0.0
RAM 90896 90896 0 0.0
pump-app-usb tlsr9518adk80d FLASH 634400 634450 50 0.0
RAM 55476 55476 0 0.0
pump-controller-app tlsr9518adk80d FLASH 611598 611648 50 0.0
RAM 52720 52720 0 0.0
shell tlsr9518adk80d FLASH 467872 467872 0 0.0
RAM 68168 68168 0 0.0
smoke_co_alarm-app tlsr9528a_retention FLASH 627912 627962 50 0.0
RAM 52320 52320 0 0.0
temperature-measurement-app-mars-ota tlsr9518adk80d FLASH 653730 653780 50 0.0
RAM 56268 56268 0 0.0
thermostat tlsr9518adk80d FLASH 638340 638390 50 0.0
RAM 53112 53112 0 0.0
window-covering tlsr9118bdk40d FLASH 524456 524506 50 0.0
RAM 97444 97444 0 0.0
tizen all-clusters-app arm unknown 4912 4912 0 0.0
FLASH 1729220 1729432 212 0.0
RAM 90180 90180 0 0.0
chip-tool-ubsan arm unknown 10792 10792 0 0.0
FLASH 18327198 18327614 416 0.0
RAM 7969512 7969852 340 0.0

@vivien-apple vivien-apple force-pushed the Logging_SubscriptionEstablished branch from ae37268 to acb5605 Compare October 17, 2024 12:27
Copy link

github-actions bot commented Oct 17, 2024

PR #36115: Size comparison from 150db87 to acb5605

Full report (82 builds for bl602, bl702, bl702l, cc13x4_26x4, cc32xx, cyw30739, efr32, esp32, linux, nrfconnect, nxp, psoc6, qpg, stm32, telink, tizen)
platform target config section 150db87 acb5605 change % change
bl602 lighting-app bl602+mfd+littlefs+rpc FLASH 1349986 1350010 24 0.0
RAM 104120 104120 0 0.0
bl702 lighting-app bl702+eth FLASH 647742 647792 50 0.0
RAM 25233 25233 0 0.0
bl702+wifi FLASH 825228 825278 50 0.0
RAM 13965 13965 0 0.0
bl706+mfd+rpc+littlefs FLASH 1054154 1054204 50 0.0
RAM 23821 23821 0 0.0
bl702l lighting-app bl702l+mfd+littlefs FLASH 974998 975052 54 0.0
RAM 16468 16468 0 0.0
cc13x4_26x4 lighting-app LP_EM_CC1354P10_6 FLASH 829564 829564 0 0.0
RAM 123452 123452 0 0.0
lock-ftd LP_EM_CC1354P10_6 FLASH 814872 814872 0 0.0
RAM 125332 125332 0 0.0
pump-app LP_EM_CC1354P10_6 FLASH 761420 761460 40 0.0
RAM 113824 113824 0 0.0
pump-controller-app LP_EM_CC1354P10_6 FLASH 745664 745704 40 0.0
RAM 114016 114016 0 0.0
cc32xx air-purifier CC3235SF_LAUNCHXL FLASH 617202 617226 24 0.0
RAM 205908 205908 0 0.0
lock CC3235SF_LAUNCHXL FLASH 657258 657282 24 0.0
RAM 206060 206060 0 0.0
cyw30739 light CYW30739B2-P5-EVK-01 unknown 2040 2040 0 0.0
FLASH 678549 678589 40 0.0
RAM 78668 78668 0 0.0
CYW30739B2-P5-EVK-02 unknown 2040 2040 0 0.0
FLASH 698393 698433 40 0.0
RAM 81300 81300 0 0.0
CYW30739B2-P5-EVK-03 unknown 2040 2040 0 0.0
FLASH 698393 698433 40 0.0
RAM 81300 81300 0 0.0
CYW930739M2EVB-02 unknown 2040 2040 0 0.0
FLASH 655329 655377 48 0.0
RAM 73736 73736 0 0.0
light-switch CYW30739B2-P5-EVK-01 unknown 2040 2040 0 0.0
FLASH 614845 614933 88 0.0
RAM 71628 71628 0 0.0
CYW30739B2-P5-EVK-02 unknown 2040 2040 0 0.0
FLASH 634473 634569 96 0.0
RAM 74180 74180 0 0.0
CYW30739B2-P5-EVK-03 unknown 2040 2040 0 0.0
FLASH 634473 634569 96 0.0
RAM 74180 74180 0 0.0
lock CYW30739B2-P5-EVK-01 unknown 2040 2040 0 0.0
FLASH 634165 634213 48 0.0
RAM 74676 74676 0 0.0
CYW30739B2-P5-EVK-02 unknown 2040 2040 0 0.0
FLASH 653873 653921 48 0.0
RAM 77228 77228 0 0.0
CYW30739B2-P5-EVK-03 unknown 2040 2040 0 0.0
FLASH 653873 653921 48 0.0
RAM 77228 77228 0 0.0
thermostat CYW30739B2-P5-EVK-01 unknown 2040 2040 0 0.0
FLASH 609477 609525 48 0.0
RAM 68764 68764 0 0.0
CYW30739B2-P5-EVK-02 unknown 2040 2040 0 0.0
FLASH 629337 629385 48 0.0
RAM 71396 71396 0 0.0
CYW30739B2-P5-EVK-03 unknown 2040 2040 0 0.0
FLASH 629337 629385 48 0.0
RAM 71396 71396 0 0.0
efr32 lock-app BRD4187C FLASH 925216 925248 32 0.0
RAM 159708 159708 0 0.0
BRD4338a FLASH 741384 741408 24 0.0
RAM 231008 231008 0 0.0
window-app BRD4187C FLASH 1018172 1018204 32 0.0
RAM 128052 128052 0 0.0
esp32 all-clusters-app c3devkit DRAM 95248 95248 0 0.0
FLASH 1539936 1540016 80 0.0
IRAM 82538 82538 0 0.0
m5stack DRAM 116192 116192 0 0.0
FLASH 1550134 1550182 48 0.0
IRAM 117039 117039 0 0.0
linux air-purifier-app debug unknown 4688 4688 0 0.0
FLASH 2781089 2781155 66 0.0
RAM 129520 129520 0 0.0
all-clusters-app debug unknown 5528 5528 0 0.0
FLASH 6092068 6092278 210 0.0
RAM 524128 524128 0 0.0
all-clusters-minimal-app debug unknown 5424 5424 0 0.0
FLASH 5422820 5422854 34 0.0
RAM 242416 242416 0 0.0
bridge-app debug unknown 5408 5408 0 0.0
FLASH 4751720 4751754 34 0.0
RAM 218384 218384 0 0.0
chip-tool debug unknown 5960 5960 0 0.0
FLASH 13161544 13161786 242 0.0
RAM 584562 584562 0 0.0
chip-tool-ipv6only arm64 unknown 21408 21408 0 0.0
FLASH 11720160 11720288 128 0.0
RAM 635480 635480 0 0.0
fabric-admin debug unknown 5792 5792 0 0.0
FLASH 11380187 11380397 210 0.0
RAM 584458 584458 0 0.0
fabric-bridge-app debug unknown 4632 4632 0 0.0
FLASH 4575352 4575386 34 0.0
RAM 205048 205048 0 0.0
lighting-app debug+rpc+ui unknown 6056 6056 0 0.0
FLASH 5693713 5693713 0 0.0
RAM 228488 228488 0 0.0
lock-app debug unknown 5344 5344 0 0.0
FLASH 4801296 4801330 34 0.0
RAM 204472 204472 0 0.0
ota-provider-app debug unknown 4720 4720 0 0.0
FLASH 4430678 4430712 34 0.0
RAM 198192 198192 0 0.0
ota-requestor-app debug unknown 4656 4656 0 0.0
FLASH 4569444 4569478 34 0.0
RAM 202760 202760 0 0.0
shell debug unknown 4216 4216 0 0.0
FLASH 3115549 3115789 240 0.0
RAM 160496 160496 0 0.0
thermostat-no-ble arm64 unknown 9448 9448 0 0.0
FLASH 4319696 4319728 32 0.0
RAM 242888 242888 0 0.0
tv-app debug unknown 5624 5624 0 0.0
FLASH 6031557 6031765 208 0.0
RAM 596416 596416 0 0.0
tv-casting-app debug unknown 5208 5208 0 0.0
FLASH 11367389 11367597 208 0.0
RAM 675936 675936 0 0.0
nrfconnect all-clusters-app nrf52840dk_nrf52840 FLASH 915512 915596 84 0.0
RAM 143359 143359 0 0.0
nrf7002dk_nrf5340_cpuapp FLASH 886016 886016 0 0.0
RAM 141498 141498 0 0.0
all-clusters-minimal-app nrf52840dk_nrf52840 FLASH 848932 848932 0 0.0
RAM 142261 142261 0 0.0
nxp contact k32w0+release FLASH 582248 582248 0 0.0
RAM 70952 70952 0 0.0
k32w1+release FLASH 597136 597176 40 0.0
RAM 63184 63184 0 0.0
mcxw71+release FLASH 596896 596936 40 0.0
RAM 63184 63184 0 0.0
light k32w0+release FLASH 618764 618812 48 0.0
RAM 70416 70416 0 0.0
k32w1+release FLASH 683112 683160 48 0.0
RAM 48816 48816 0 0.0
mcxw71+release FLASH 683128 683176 48 0.0
RAM 48816 48816 0 0.0
lock k32w1+release FLASH 705480 705528 48 0.0
RAM 67324 67324 0 0.0
mcxw71+release FLASH 705504 705552 48 0.0
RAM 67324 67324 0 0.0
psoc6 all-clusters cy8ckit_062s2_43012 FLASH 1647556 1647644 88 0.0
RAM 212408 212408 0 0.0
all-clusters-minimal cy8ckit_062s2_43012 FLASH 1553620 1553636 16 0.0
RAM 209208 209208 0 0.0
light cy8ckit_062s2_43012 FLASH 1467956 1467988 32 0.0
RAM 201200 201200 0 0.0
lock cy8ckit_062s2_43012 FLASH 1464932 1464964 32 0.0
RAM 225560 225560 0 0.0
qpg lighting-app qpg6105+debug FLASH 660560 660608 48 0.0
RAM 105396 105396 0 0.0
lock-app qpg6105+debug FLASH 618580 618620 40 0.0
RAM 99864 99864 0 0.0
stm32 light STM32WB5MM-DK FLASH 481896 481944 48 0.0
RAM 144844 144844 0 0.0
telink air-quality-sensor-app tlsr9528a_retention FLASH 620998 621048 50 0.0
RAM 50648 50648 0 0.0
all-clusters-app tlsr9118bdk40d FLASH 689376 689452 76 0.0
RAM 149488 149488 0 0.0
all-clusters-minimal-app tlsr9528a FLASH 782368 782418 50 0.0
RAM 111440 111440 0 0.0
bridge-app tlsr9258a FLASH 681098 681148 50 0.0
RAM 91304 91304 0 0.0
contact-sensor-app tlsr9528a_retention FLASH 620762 620812 50 0.0
RAM 50600 50600 0 0.0
light-switch-app-ota-shell-factory-data tlsr9528a FLASH 708716 708792 76 0.0
RAM 73940 73940 0 0.0
lighting-app-ota-factory-data tlsr9118bdk40d FLASH 625712 625762 50 0.0
RAM 144468 144468 0 0.0
lighting-app-ota-rpc-factory-data-4mb tlsr9518adk80d FLASH 811720 811770 50 0.0
RAM 99100 99100 0 0.0
lock-app-dfu tlsr9528a FLASH 656668 656718 50 0.0
RAM 66660 66660 0 0.0
ota-requestor-app tlsr9258a FLASH 697076 697126 50 0.0
RAM 90896 90896 0 0.0
pump-app-usb tlsr9518adk80d FLASH 634400 634450 50 0.0
RAM 55476 55476 0 0.0
pump-controller-app tlsr9518adk80d FLASH 611598 611648 50 0.0
RAM 52720 52720 0 0.0
shell tlsr9518adk80d FLASH 467872 467872 0 0.0
RAM 68168 68168 0 0.0
smoke_co_alarm-app tlsr9528a_retention FLASH 627912 627962 50 0.0
RAM 52320 52320 0 0.0
temperature-measurement-app-mars-ota tlsr9518adk80d FLASH 653730 653780 50 0.0
RAM 56268 56268 0 0.0
thermostat tlsr9518adk80d FLASH 638340 638390 50 0.0
RAM 53112 53112 0 0.0
window-covering tlsr9118bdk40d FLASH 524456 524506 50 0.0
RAM 97444 97444 0 0.0
tizen all-clusters-app arm unknown 4912 4912 0 0.0
FLASH 1729220 1729432 212 0.0
RAM 90180 90180 0 0.0
chip-tool-ubsan arm unknown 10792 10792 0 0.0
FLASH 18327198 18327614 416 0.0
RAM 7969512 7969852 340 0.0

@mergify mergify bot merged commit 76e9e14 into project-chip:master Oct 18, 2024
70 checks passed
yyzhong-g pushed a commit to yyzhong-g/connectedhomeip that referenced this pull request Dec 12, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants