Move chip::Logging::LogV to platform-specific implementation

[andy31415]

Problem

Logging is defined in both libSupport and platform, with many defines configuring where support goes.

Logging in general is platform-dependent.

Summary of Changes

• Move logging to platform-dependent (nrfconnect and Darwin required this)
• removed stdio with timestamp logging (nothing was using this)
• android is special cased for the logging implementation since it has no platform (some ideas on how to make this better would be nice. Maybe android does need a platform after all, even if incomplete)

[mspang]

This exacerbates a dependency cycle.

Logging is needed throughout the codebase. "platform" depends on and uses much of CHIP.

I think we need to take a step back and consider how we want ports to work and what's more important - having a semblance of layering, or of reducing the number of places ports need to add their code.

I value the layering as it simplifies how much code we need to think about and can test independent parts, but if we want to have a single place that ports add code, it's probably not possible to have much layering. This PR basically implies that all portable code depends on all platform specific code, and vice versa, in a big knot.

[mspang]

Concrete example -

Should an executable that just does main() { Log("Hello World") } necessarily bring in the CHIP Bluetooth Transport Protocol implementation? Including not only the platform's BLE code, but also CHIP's protocols built on top?

If yes, this PR is OK. If no, we need to take another route.

[andy31415]

Concrete example -

Should an executable that just does main() { Log("Hello World") } necessarily bring in the CHIP Bluetooth Transport Protocol implementation? Including not only the platform's BLE code, but also CHIP's protocols built on top?

If yes, this PR is OK. If no, we need to take another route.

Agree this is still a mess. I will try to figure it out a bit more.

What bothers me is that there are two places where logs are configured: support and platform. On top of this, the support version is filled with #ifdefs to try to support various possiblities (however platform-dependent implementations still seem to be required).

I am thinking to have 'platform::logging' independent from the rest.
The example you gave seems to show that we have not split platform enough. Ideally things should be split as 'BLE', 'Inet', 'Flash' etc.

[mspang]

Concrete example -
Should an executable that just does main() { Log("Hello World") } necessarily bring in the CHIP Bluetooth Transport Protocol implementation? Including not only the platform's BLE code, but also CHIP's protocols built on top?
If yes, this PR is OK. If no, we need to take another route.

Agree this is still a mess. I will try to figure it out a bit more.

What bothers me is that there are two places where logs are configured: support and platform. On top of this, the support version is filled with #ifdefs to try to support various possiblities (however platform-dependent implementations still seem to be required).

I am thinking to have 'platform::logging' independent from the rest.
The example you gave seems to show that we have not split platform enough. Ideally things should be split as 'BLE', 'Inet', 'Flash' etc.

platform code is somewhat split today. We have platform code in support, inet, lwip, etc. The premise that all platform code goes in platform/ is currently false; src/platform is this specific "device layer" component not the location of all of the platform specific code.

Agree that ifdefs are problematic, external porters can't add ifdefs without forking the code. We need to fix that, and doing something like pigweed's pw_log would make sense here.

[andy31415]

I'll echo what @mspang said, this change increases the number of directories that a new platform has touch. Which, philosophically, we should avoid. I don't have a good suggestion here, but it does feel wrong to have a cc13x2_26x2 target in the common logging directory.

On a slight tangent, is there a way to define the original log site? The Log() and LogV() definitions are currently in a platform interface header. Assuming the formatting string is constant, we have some tools in our SDK that I would like to take advantage of to elide them from the executable.

I also feel uneasy about having several platform-specific directories. I could push the logging code back into the platforms themselves. The current state of the code was me going through several refactoring phases. Would that work better?

I.e. I have changed the code to things like : public_deps += [ "${chip_root}/src/platform/logging:efr32"] which makes it clear what logging is used, however I can always put back the Logging.cpp into the platform itself. I will keep stdio and android as stand-alone (because android has no platform and stdio seems to be a generic POSIX support).

Thoughts? @mspang @srickardti

[andy31415]

@mspang @srickardti - I moved logging back into the platform directories.

I kept android and stdio as standalone.

[mspang]

We've gone full circle now; the cycle I mentioned earlier in the review process is back.

Single platform target and acyclic structure are contradictory outcomes given the premises that everything depends on logging and other parts of the "platform" layer depend on a decent chunk of CHIP. That's why I asked for more input - something has to give, we cannot achieve all of the desired outcomes.

In my hello world example (#4741 (comment)), we now have that logging necessarily brings in CHIP protocol again. I think it's a shame but if we think that putting all the platform code in one library is more useful, I can accept it.

[mspang]

This is highly surprising, why? Can you at least at a TODO to move this dependency out of the test suite template?

[andy31415]

Without it I get

...
.../lib/libnlunit-test.a  -ldl -lpthread -lrt -Wl,--end-group -o linux_x64_clang/tests/TestInetEndPoint
ld.lld: error: undefined symbol: chip::Logging::Platform::LogV(char const*, unsigned char, char const*, __va_list_tag*)
>>> referenced by CHIPLogging.cpp:137 (../../src/lib/support/logging/CHIPLogging.cpp:137)
>>>               libSupportLayer.CHIPLogging.cpp.o:(chip::Logging::LogV(unsigned char, unsigned char, char const*, __va_list_tag*)) in archive linux_x64_clang/obj/src/lib/support/lib/libSupportLayer.a

I believe the unit test for system may have a customized event loop (not pulling in the device layer) but are lacking a vlog implementation. Previous versions seem to have some hardcoded __attribute__((weak)) vlog implementations, but that seemed really hacky so I killed them.

A future pass should add the logging binding only for the tests that need it. Then again, do any tests without logging make sense? I think we need to follow up and figure if there is a split between tests without a platform layer vs tests with one.

[mspang]

What you're seeing here is that the way you've avoided the cycle is to remove a dependency that's needed to link (It's not needed to compile.)

Re-adding the dependency at the test suite level fixes the link error, but it is not the right solution from my perspective - target should list all of their link-time dependencies generally speaking. This is what I meant by resolving cycles in a way that allows unit tests to link without additional dependencies - here, stdio is such an "additional dependency".

[todo]

figure out a way to auto-define dependency on stdio logging.

connectedhomeip/build/chip/chip_test_suite.gni

Lines 92 to 102 in 8b5882c

	# TODO: figure out a way to auto-define dependency on stdio logging.
	# This dep is required since libSupportLayer now does not include
	# a default implementation.
	#
	# Tests such as TestInetEndPoint need to exercise the system event
	# loop however they do not seem to include a logging binding so this
	# is forcefully added here.
	public_deps += [ "${chip_root}/src/platform/logging:stdio" ]
	}
	if (chip_link_tests) {

---

This comment was generated by todo based on a TODO comment in 8b5882c in #4741. cc @andy31415.

[github-actions]

Size increase report for "nrfconnect-example-build" from 589eb1b

File	Section	File	VM
chip-lighting.elf	rodata	8	8
chip-lighting.elf	shell_root_cmds_sections	4	4
chip-lighting.elf	text	-4	-4
chip-lock.elf	rodata	8	8
chip-lock.elf	shell_root_cmds_sections	4	4
chip-lock.elf	text	-4	-4
chip-shell.elf	rodata	8	8
chip-shell.elf	text	-4	-4
chip-shell.elf	log_const_sections	-12	-12

Full report output

BLOAT REPORT

Files found only in the build output:
    report.csv

Comparing ./master_artifact/chip-lighting.elf and ./pull_artifact/chip-lighting.elf:

sections,vmsize,filesize
.debug_line,0,3751
.symtab,0,16
.strtab,0,13
rodata,8,8
shell_root_cmds_sections,4,4
.shstrtab,0,-1
text,-4,-4
.debug_aranges,0,-8
.debug_frame,0,-24
.debug_ranges,0,-72
.debug_str,0,-88
.debug_loc,0,-280
.debug_abbrev,0,-3079
.debug_info,0,-16072

Comparing ./master_artifact/chip-lock.elf and ./pull_artifact/chip-lock.elf:

sections,vmsize,filesize
.debug_line,0,3753
.symtab,0,16
.strtab,0,13
rodata,8,8
shell_root_cmds_sections,4,4
.shstrtab,0,-1
text,-4,-4
.debug_aranges,0,-8
.debug_frame,0,-24
.debug_ranges,0,-72
.debug_str,0,-88
.debug_loc,0,-280
.debug_abbrev,0,-3080
.debug_info,0,-16073

Comparing ./master_artifact/chip-shell.elf and ./pull_artifact/chip-shell.elf:

sections,vmsize,filesize
.debug_line,0,799
.symtab,0,16
.strtab,0,13
rodata,8,8
.shstrtab,0,3
text,-4,-4
.debug_aranges,0,-8
log_const_sections,-12,-12
.debug_frame,0,-24
.debug_ranges,0,-72
.debug_str,0,-88
.debug_loc,0,-272
.debug_abbrev,0,-2259
.debug_info,0,-15788

[github-actions]

Size increase report for "esp32-example-build" from 589eb1b

File	Section	File	VM
chip-pigweed-app.elf	.flash.rodata	4	4
chip-pigweed-app.elf	.flash.text	-28	-28
chip-all-clusters-app.elf	.flash.text	-28	-28

Full report output

BLOAT REPORT

Files found only in the build output:
    report.csv

Comparing ./master_artifact/chip-pigweed-app.elf and ./pull_artifact/chip-pigweed-app.elf:

sections,vmsize,filesize
.strtab,0,16
.flash.rodata,4,4
.xt.prop._ZSt9__find_ifIPKSt4byteN9__gnu_cxx5__ops10_Iter_predIPFbS0_EEEET_S9_S9_T0_St26random_access_iterator_tag,0,1
[Unmapped],0,-4
.debug_aranges,0,-8
.debug_ranges,0,-8
.debug_frame,0,-24
.flash.text,-28,-28
.debug_loc,0,-97
.debug_line,0,-2087
.debug_abbrev,0,-2161
.debug_str,0,-5590
.debug_info,0,-31242

Comparing ./master_artifact/chip-all-clusters-app.elf and ./pull_artifact/chip-all-clusters-app.elf:

sections,vmsize,filesize
.debug_line,0,10714
.strtab,0,16
.xt.prop._ZTVN4chip11DeviceLayer37DeviceNetworkProvisioningDelegateImplE,0,-2
.debug_aranges,0,-8
.debug_ranges,0,-8
.debug_frame,0,-24
.flash.text,-28,-28
.debug_str,0,-72
.debug_loc,0,-107
.debug_abbrev,0,-3902
.debug_info,0,-32955