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

Introduce ACL logging verbosity control #17354

Merged

Conversation

tcarmelveilleux
Copy link
Contributor

Problem

  • When bringing-up an AccessControl::Delegate, extra policy
    verbose logging is helpful. However, extra verbose logging
    is currently always enabled, which takes a lot of logging buffer
    space when complex transactions (long paths, wildcards) are used,
    to just emit debug data.
  • Current method to turn it down is to turn off all progress logging,
    but progress logging may have a lot of important details.

Issue #14449

Change overview

This PR introduces a logging verbosity control for Access Control,
using the chip_access_control_policy_logging_verbosity build
config variable.

High verbosity is maintained in linux/Darwin *-app, but turned
down by default elsewhere.

Testing

  • unit tests still pass
  • integration tests still pass
  • logs are less on m5stack
  • logs are fully verbose on linux

- When bringing-up an AccessControl::Delegate, extra policy
  verbose logging is helpful. However, extra verbose logging
  is currently always enabled, which takes a lot of logging buffer
  space when complex transactions (long paths, wildcards) are used,
  to just emit debug data.
- Current method to turn it down is to turn off all progress logging,
  but progress logging may have a lot of important details.

This PR introduces a logging verbosity control for Access Control,
using the `chip_access_control_policy_logging_verbosity` build
config variable.

High verbosity is maintained in linux/Darwin *-app, but turned
down by default elsewhere.

Issue project-chip#14449

Testing done:
- unit tests still pass
- integration tests still pass
- logs are less on m5stack
- logs are fully verbose on linux
@tcarmelveilleux tcarmelveilleux added the acl Access Control feature label Apr 13, 2022
@boring-cyborg boring-cyborg bot added the app label Apr 13, 2022
Copy link
Contributor

@mlepage-google mlepage-google left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We'll likely still fine tune the logging at various levels, but it's a good start.

src/app/BUILD.gn Show resolved Hide resolved
@github-actions
Copy link

github-actions bot commented Apr 13, 2022

PR #17354: Size comparison from 20be070 to 387b626

Increases above 0.2%:

platform target config section 20be070 387b626 change % change
linux ota-provider-app debug (read/write) 115040 115296 256 0.2
.bss 47968 48224 256 0.5
Increases (30 builds for cc13x2_26x2, cyw30739, efr32, esp32, k32w, linux, mbed, nrfconnect, p6, telink)
platform target config section 20be070 387b626 change % change
cc13x2_26x2 lock-ftd LP_CC2652R7 (read/write) 151212 151220 8 0.0
.bss 74144 74152 8 0.0
lock-mtd LP_CC2652R7 (read/write) 146932 146940 8 0.0
.bss 69864 69872 8 0.0
pump-app LP_CC2652R7 (read/write) 152508 152516 8 0.0
.bss 74640 74648 8 0.0
pump-controller-app LP_CC2652R7 (read/write) 152176 152184 8 0.0
.bss 74344 74352 8 0.0
cyw30739 light cyw930739m2evb_01 .bss 75956 75964 8 0.0
lock cyw930739m2evb_01 .bss 74452 74460 8 0.0
ota-requestor-no-progress-logging cyw930739m2evb_01 .bss 83784 83792 8 0.0
efr32 lighting-app BRD4161A (read/write) 133144 133152 8 0.0
.bss 131104 131112 8 0.0
BRD4161A+rpc (read/write) 149828 149836 8 0.0
.bss 147584 147592 8 0.0
window-app BRD4161A (read/write) 131148 131156 8 0.0
.bss 129200 129208 8 0.0
esp32 all-clusters-app c3devkit .dram0.bss 62624 62632 8 0.0
m5stack .dram0.bss 68144 68152 8 0.0
k32w light k32w061+release .bss 78128 78136 8 0.0
lock k32w061+release .bss 78704 78712 8 0.0
linux all-clusters-app debug (read only) 2697841 2697873 32 0.0
(read/write) 149216 149248 32 0.0
.bss 60192 60224 32 0.1
.text 2291426 2291458 32 0.0
bridge-app debug+rpc (read only) 1837453 1837597 144 0.0
.text 1570517 1570661 144 0.0
chip-tool debug (read only) 10684325 10684389 64 0.0
.text 9315925 9315989 64 0.0
chip-tool-no-interactive-ipv6only arm64 (read only) 10283796 10283860 64 0.0
.text 8667236 8667300 64 0.0
door-lock-app debug (read only) 2108817 2108849 32 0.0
.text 1766418 1766450 32 0.0
lighting-app debug+rpc (read/write) 127920 127952 32 0.0
.bss 50272 50304 32 0.1
ota-provider-app debug (read/write) 115040 115296 256 0.2
.bss 47968 48224 256 0.5
.rodata 172515 172547 32 0.0
ota-requestor-app debug (read only) 2076409 2076441 32 0.0
.text 1748962 1748994 32 0.0
shell debug (read only) 2525713 2525745 32 0.0
.text 2149810 2149842 32 0.0
thermostat-no-ble arm64 (read only) 2353476 2353508 32 0.0
(read/write) 151121 151137 16 0.0
.bss 63153 63169 16 0.0
.text 1980352 1980384 32 0.0
mbed lock-app CY8CPROTO_062_4343W+release .bss 185236 185244 8 0.0
nrfconnect all-clusters-app nrf52840dk_nrf52840 bss 136528 136536 8 0.0
p6 all-clusters-app default .bss 118640 118648 8 0.0
light-app default .bss 112136 112144 8 0.0
lock-app default .bss 111880 111888 8 0.0
telink lighting-app tlsr9518adk80d bss 69988 69996 8 0.0
Decreases (23 builds for cc13x2_26x2, cyw30739, efr32, esp32, k32w, linux, mbed, nrfconnect, p6, telink)
platform target config section 20be070 387b626 change % change
cc13x2_26x2 lock-ftd LP_CC2652R7 (read only) 640435 639647 -788 -0.1
.rodata 80227 79879 -348 -0.4
.text 559716 559276 -440 -0.1
lock-mtd LP_CC2652R7 (read only) 589171 588391 -780 -0.1
.rodata 80107 79759 -348 -0.4
.text 508572 508140 -432 -0.1
pump-app LP_CC2652R7 (read only) 648519 648403 -116 -0.0
.rodata 75415 75363 -52 -0.1
.text 572616 572552 -64 -0.0
pump-controller-app LP_CC2652R7 (read only) 642499 641695 -804 -0.1
.rodata 79051 78695 -356 -0.5
.text 562960 562512 -448 -0.1
cyw30739 light cyw930739m2evb_01 (read/write) 619042 618286 -756 -0.1
.app_xip_area 525752 524988 -764 -0.1
lock cyw930739m2evb_01 (read/write) 576638 575894 -744 -0.1
.app_xip_area 484884 484132 -752 -0.2
ota-requestor-no-progress-logging cyw930739m2evb_01 (read/write) 565170 565146 -24 -0.0
.app_xip_area 463788 463756 -32 -0.0
efr32 lighting-app BRD4161A (read only) 908068 907260 -808 -0.1
.text 908060 907252 -808 -0.1
BRD4161A+rpc (read only) 942436 941620 -816 -0.1
.text 942428 941612 -816 -0.1
window-app BRD4161A (read only) 844724 843900 -824 -0.1
.text 844716 843892 -824 -0.1
esp32 all-clusters-app c3devkit (read only) 979976 979518 -458 -0.0
(read/write) 1397578 1397338 -240 -0.0
.flash.rodata 201616 201360 -256 -0.1
.flash.text 979976 979518 -458 -0.0
m5stack (read only) 1035487 1034959 -528 -0.1
(read/write) 465316 465092 -224 -0.0
.flash.rodata 231184 230952 -232 -0.1
.flash.text 1030103 1029575 -528 -0.1
k32w light k32w061+release (read/write) 687260 686780 -480 -0.1
.text 601296 600808 -488 -0.1
lock k32w061+release (read/write) 691892 691152 -740 -0.1
.text 605392 604644 -748 -0.1
linux lighting-app debug+rpc (read only) 2313657 2313385 -272 -0.0
.rodata 182665 182601 -64 -0.0
.text 1965154 1964946 -208 -0.0
ota-provider-app debug (read only) 2046033 2046009 -24 -0.0
.text 1717330 1717250 -80 -0.0
tv-app debug (read only) 2797649 2797569 -80 -0.0
.rodata 213387 213323 -64 -0.0
.text 2402962 2402946 -16 -0.0
mbed lock-app CY8CPROTO_062_4343W+release (read/write) 2369412 2368780 -632 -0.0
.text 1332012 1331380 -632 -0.0
nrfconnect all-clusters-app nrf52840dk_nrf52840 (read/write) 1163491 1162699 -792 -0.1
rodata 147364 147020 -344 -0.2
text 800968 800528 -440 -0.1
p6 all-clusters-app default (read/write) 2515120 2514472 -648 -0.0
.text 1473384 1472736 -648 -0.0
light-app default (read/write) 2415592 2414928 -664 -0.0
.text 1373856 1373192 -664 -0.0
lock-app default (read/write) 2379160 2378496 -664 -0.0
.text 1337424 1336760 -664 -0.0
telink lighting-app tlsr9518adk80d (read/write) 801524 800644 -880 -0.1
text 570136 569612 -524 -0.1
Full report (31 builds for cc13x2_26x2, cyw30739, efr32, esp32, k32w, linux, mbed, nrfconnect, p6, telink)
platform target config section 20be070 387b626 change % change
cc13x2_26x2 lock-ftd LP_CC2652R7 (read only) 640435 639647 -788 -0.1
(read/write) 151212 151220 8 0.0
.bss 74144 74152 8 0.0
.data 3212 3212 0 0.0
.rodata 80227 79879 -348 -0.4
.text 559716 559276 -440 -0.1
lock-mtd LP_CC2652R7 (read only) 589171 588391 -780 -0.1
(read/write) 146932 146940 8 0.0
.bss 69864 69872 8 0.0
.data 3212 3212 0 0.0
.rodata 80107 79759 -348 -0.4
.text 508572 508140 -432 -0.1
pump-app LP_CC2652R7 (read only) 648519 648403 -116 -0.0
(read/write) 152508 152516 8 0.0
.bss 74640 74648 8 0.0
.data 3244 3244 0 0.0
.rodata 75415 75363 -52 -0.1
.text 572616 572552 -64 -0.0
pump-controller-app LP_CC2652R7 (read only) 642499 641695 -804 -0.1
(read/write) 152176 152184 8 0.0
.bss 74344 74352 8 0.0
.data 3208 3208 0 0.0
.rodata 79051 78695 -356 -0.5
.text 562960 562512 -448 -0.1
cyw30739 light cyw930739m2evb_01 (read/write) 619042 618286 -756 -0.1
.app_xip_area 525752 524988 -764 -0.1
.bss 75956 75964 8 0.0
.data 684 684 0 0.0
.rodata 0 0 0 0.0
.text 0 0 0 0.0
lock cyw930739m2evb_01 (read/write) 576638 575894 -744 -0.1
.app_xip_area 484884 484132 -752 -0.2
.bss 74452 74460 8 0.0
.data 648 648 0 0.0
.rodata 0 0 0 0.0
.text 0 0 0 0.0
ota-requestor-no-progress-logging cyw930739m2evb_01 (read/write) 565170 565146 -24 -0.0
.app_xip_area 463788 463756 -32 -0.0
.bss 83784 83792 8 0.0
.data 564 564 0 0.0
.rodata 0 0 0 0.0
.text 112 112 0 0.0
efr32 lighting-app BRD4161A (read only) 908068 907260 -808 -0.1
(read/write) 133144 133152 8 0.0
.bss 131104 131112 8 0.0
.data 2040 2040 0 0.0
.text 908060 907252 -808 -0.1
BRD4161A+rpc (read only) 942436 941620 -816 -0.1
(read/write) 149828 149836 8 0.0
.bss 147584 147592 8 0.0
.data 2244 2244 0 0.0
.text 942428 941612 -816 -0.1
window-app BRD4161A (read only) 844724 843900 -824 -0.1
(read/write) 131148 131156 8 0.0
.bss 129200 129208 8 0.0
.data 1948 1948 0 0.0
.text 844716 843892 -824 -0.1
esp32 all-clusters-app c3devkit (read only) 979976 979518 -458 -0.0
(read/write) 1397578 1397338 -240 -0.0
.dram0.bss 62624 62632 8 0.0
.dram0.data 14420 14420 0 0.0
.flash.rodata 201616 201360 -256 -0.1
.flash.text 979976 979518 -458 -0.0
.iram0.text 62016 62016 0 0.0
m5stack (read only) 1035487 1034959 -528 -0.1
(read/write) 465316 465092 -224 -0.0
.dram0.bss 68144 68152 8 0.0
.dram0.data 34152 34152 0 0.0
.flash.rodata 231184 230952 -232 -0.1
.flash.text 1030103 1029575 -528 -0.1
.iram0.text 123107 123107 0 0.0
k32w light k32w061+release (read/write) 687260 686780 -480 -0.1
.bss 78128 78136 8 0.0
.data 2036 2036 0 0.0
.text 601296 600808 -488 -0.1
lock k32w061+release (read/write) 691892 691152 -740 -0.1
.bss 78704 78712 8 0.0
.data 1996 1996 0 0.0
.text 605392 604644 -748 -0.1
linux all-clusters-app debug (read only) 2697841 2697873 32 0.0
(read/write) 149216 149248 32 0.0
.bss 60192 60224 32 0.1
.data 1888 1888 0 0.0
.data.rel.ro 81080 81080 0 0.0
.dynamic 608 608 0 0.0
.got 4456 4456 0 0.0
.init 27 27 0 0.0
.init_array 984 984 0 0.0
.rodata 232421 232421 0 0.0
.text 2291426 2291458 32 0.0
bridge-app debug+rpc (read only) 1837453 1837597 144 0.0
(read/write) 91856 91856 0 0.0
.bss 44480 44480 0 0.0
.data 2912 2912 0 0.0
.data.rel.ro 39376 39376 0 0.0
.dynamic 592 592 0 0.0
.got 3936 3936 0 0.0
.init 27 27 0 0.0
.init_array 552 552 0 0.0
.rodata 148505 148505 0 0.0
.text 1570517 1570661 144 0.0
chip-tool debug (read only) 10684325 10684389 64 0.0
(read/write) 371832 371832 0 0.0
.bss 22752 22752 0 0.0
.data 1104 1104 0 0.0
.data.rel.ro 341728 341728 0 0.0
.dynamic 624 624 0 0.0
.got 4936 4936 0 0.0
.init 27 27 0 0.0
.init_array 656 656 0 0.0
.rodata 539093 539093 0 0.0
.text 9315925 9315989 64 0.0
chip-tool-no-interactive-ipv6only arm64 (read only) 10283796 10283860 64 0.0
(read/write) 492273 492273 0 0.0
.bss 41025 41025 0 0.0
.data 1168 1168 0 0.0
.data.rel.ro 388840 388840 0 0.0
.dynamic 560 560 0 0.0
.got 57440 57440 0 0.0
.init 24 24 0 0.0
.init_array 184 184 0 0.0
.rodata 513140 513140 0 0.0
.text 8667236 8667300 64 0.0
door-lock-app debug (read only) 2108817 2108849 32 0.0
(read/write) 119600 119600 0 0.0
.bss 48064 48064 0 0.0
.data 1472 1472 0 0.0
.data.rel.ro 64504 64504 0 0.0
.dynamic 592 592 0 0.0
.got 4264 4264 0 0.0
.init 27 27 0 0.0
.init_array 680 680 0 0.0
.rodata 186697 186697 0 0.0
.text 1766418 1766450 32 0.0
lighting-app debug+rpc (read only) 2313657 2313385 -272 -0.0
(read/write) 127920 127952 32 0.0
.bss 50272 50304 32 0.1
.data 1952 1952 0 0.0
.data.rel.ro 69992 69992 0 0.0
.dynamic 608 608 0 0.0
.got 4312 4312 0 0.0
.init 27 27 0 0.0
.init_array 776 776 0 0.0
.rodata 182665 182601 -64 -0.0
.text 1965154 1964946 -208 -0.0
ota-provider-app debug (read only) 2046033 2046009 -24 -0.0
(read/write) 115040 115296 256 0.2
.bss 47968 48224 256 0.5
.data 1608 1608 0 0.0
.data.rel.ro 59720 59720 0 0.0
.dynamic 608 608 0 0.0
.got 4464 4464 0 0.0
.init 27 27 0 0.0
.init_array 632 632 0 0.0
.rodata 172515 172547 32 0.0
.text 1717330 1717250 -80 -0.0
ota-requestor-app debug (read only) 2076409 2076441 32 0.0
(read/write) 118392 118392 0 0.0
.bss 48960 48960 0 0.0
.data 1864 1864 0 0.0
.data.rel.ro 61960 61960 0 0.0
.dynamic 592 592 0 0.0
.got 4304 4304 0 0.0
.init 27 27 0 0.0
.init_array 656 656 0 0.0
.rodata 169388 169388 0 0.0
.text 1748962 1748994 32 0.0
shell debug (read only) 2525713 2525745 32 0.0
(read/write) 150064 150064 0 0.0
.bss 67624 67624 0 0.0
.data 1264 1264 0 0.0
.data.rel.ro 75464 75464 0 0.0
.dynamic 592 592 0 0.0
.got 4168 4168 0 0.0
.init 27 27 0 0.0
.init_array 928 928 0 0.0
.rodata 214738 214738 0 0.0
.text 2149810 2149842 32 0.0
thermostat-no-ble arm64 (read only) 2353476 2353508 32 0.0
(read/write) 151121 151137 16 0.0
.bss 63153 63169 16 0.0
.data 1424 1424 0 0.0
.data.rel.ro 78752 78752 0 0.0
.dynamic 560 560 0 0.0
.got 4768 4768 0 0.0
.init 24 24 0 0.0
.init_array 368 368 0 0.0
.rodata 144548 144548 0 0.0
.text 1980352 1980384 32 0.0
tv-app debug (read only) 2797649 2797569 -80 -0.0
(read/write) 250784 250784 0 0.0
.bss 164112 164112 0 0.0
.data 4448 4448 0 0.0
.data.rel.ro 76008 76008 0 0.0
.dynamic 592 592 0 0.0
.got 4688 4688 0 0.0
.init 27 27 0 0.0
.init_array 904 904 0 0.0
.rodata 213387 213323 -64 -0.0
.text 2402962 2402946 -16 -0.0
mbed lock-app CY8CPROTO_062_4343W+release (read only) 6224 6224 0 0.0
(read/write) 2369412 2368780 -632 -0.0
.bss 185236 185244 8 0.0
.data 5840 5840 0 0.0
.text 1332012 1331380 -632 -0.0
nrfconnect all-clusters-app nrf52840dk_nrf52840 (read/write) 1163491 1162699 -792 -0.1
bss 136528 136536 8 0.0
rodata 147364 147020 -344 -0.2
text 800968 800528 -440 -0.1
p6 all-clusters-app default (read/write) 2515120 2514472 -648 -0.0
.bss 118640 118648 8 0.0
.data 2768 2768 0 0.0
.text 1473384 1472736 -648 -0.0
light-app default (read/write) 2415592 2414928 -664 -0.0
.bss 112136 112144 8 0.0
.data 2576 2576 0 0.0
.text 1373856 1373192 -664 -0.0
lock-app default (read/write) 2379160 2378496 -664 -0.0
.bss 111880 111888 8 0.0
.data 2536 2536 0 0.0
.text 1337424 1336760 -664 -0.0
telink lighting-app tlsr9518adk80d (read/write) 801524 800644 -880 -0.1
bss 69988 69996 8 0.0
noinit 40416 40416 0 0.0
text 570136 569612 -524 -0.1

@bzbarsky-apple bzbarsky-apple merged commit 085acd0 into project-chip:master Apr 14, 2022
andrei-menzopol pushed a commit to andrei-menzopol/connectedhomeip that referenced this pull request Apr 14, 2022
* Introduce ACL logging verbosity control

- When bringing-up an AccessControl::Delegate, extra policy
  verbose logging is helpful. However, extra verbose logging
  is currently always enabled, which takes a lot of logging buffer
  space when complex transactions (long paths, wildcards) are used,
  to just emit debug data.
- Current method to turn it down is to turn off all progress logging,
  but progress logging may have a lot of important details.

This PR introduces a logging verbosity control for Access Control,
using the `chip_access_control_policy_logging_verbosity` build
config variable.

High verbosity is maintained in linux/Darwin *-app, but turned
down by default elsewhere.

Issue project-chip#14449

Testing done:
- unit tests still pass
- integration tests still pass
- logs are less on m5stack
- logs are fully verbose on linux

* Restyled by clang-format

* Restyled by gn

* Fix CI

Co-authored-by: Restyled.io <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
acl Access Control feature app review - approved
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants