trace: Add tracing for prepared secure messages #16565

rgoliver · 2022-03-23T13:21:06Z

Problem

It would be helpful to have the prepared secure messages to validate some CSG tests.

Change overview

Add new traces for the prepared messages for send and receive.
Add handlers to pack the data into the json, which can either be streamed to the log or a file using the command line arguments.

Note: This is only enabled when CHIP_CONFIG_TRANSPORT_TRACE is enabled, otherwise this is a no-op.

Testing

ran chip-tool with logging:

chip-tool pairing ble-wifi $node_id $ssid $pass 32423 0 --trace_file trace.log

output snippet:

[1648041423.353875]	SecureMsg.SecMsgSent
    json	{"msg_counter": 647868007, "source_node_id": 8183665693545772584, "session_id": 0, "msg_flags": 4, "security_flags": 0, "exchange_flags": 1, "exchange_id": 31693, "protocol_id": 0, "protocol_opcode": 32, "is_initiator": true, "is_ack_requested": false, "payload_size": 56, "payload_hex": "15300120af17db5285e0d18f09b7199e0be44821e3ce276196f63fb901a747280f5c0d7f240201240300280435052501881325022c011818"}

[1648041423.353908]	SecureMsg.PreparedMsgSent
    json	{"destination": "BLE", "payload_size": 78, "payload_hex": "0400000067ae9d2628b658e0963892710120cd7b000015300120af17db5285e0d18f09b7199e0be44821e3ce276196f63fb901a747280f5c0d7f240201240300280435052501881325022c011818", "buffer_ptr": 140224441100048}

[1648041424.602071]	SecureMsg.PreparedMsgReceived
    json	{"source": "BLE", "payload_size": 134, "payload_hex": "01000000046df14028b658e0963892710021cd7b000015300120af17db5285e0d18f09b7199e0be44821e3ce276196f63fb901a747280f5c0d7f30022008b40ee8183f8d1a2591d83a9360d0725a915d3832560034c25d65e387deb70324030135042501e8033002105350414b453250204b65792053616c741835052501881325022c011818", "buffer_ptr": 140224441144912}

[1648041424.602313]	SecureMsg.SecMsgReceived
    json	{"peer_address": "BLE", "msg_counter": 1089563908, "dest_node_id": 8183665693545772584, "session_id": 0, "msg_flags": 1, "security_flags": 0, "exchange_flags": 0, "exchange_id": 31693, "protocol_id": 0, "protocol_opcode": 33, "is_initiator": false, "is_ack_requested": false, "payload_size": 112, "payload_hex": "15300120af17db5285e0d18f09b7199e0be44821e3ce276196f63fb901a747280f5c0d7f30022008b40ee8183f8d1a2591d83a9360d0725a915d3832560034c25d65e387deb70324030135042501e8033002105350414b453250204b65792053616c741835052501881325022c011818"}

- Add new traces for the prepared messages for send and receive. - Add handlers to pack the data into json. Note: This is only enabled when CHIP_CONFIG_TRANSPORT_TRACE is enabled, otherwise this is a no-op.

github-actions · 2022-03-23T13:48:58Z

PR #16565: Size comparison from 7172ac9 to e249aa0

Increases (11 builds for linux)

platform	target	config	section	`7172ac9`	`e249aa0`	change
linux	all-clusters-app	debug	(read only)	2478329	2478361	32
			.rodata	211941	211973	32
	bridge-app	debug+rpc	(read only)	1753373	`1753405`	32
			.rodata	144556	144588	32
	chip-tool	debug	(read only)	10163805	10166525	2720
			.rodata	518677	518805	128
			.text	8862405	8864997	2592
	chip-tool-ipv6only	arm64	(read only)	9785084	`9786716`	1632
			.rodata	494308	494356	48
			.text	8238692	8240276	1584
	door-lock-app	debug	(read only)	2005129	2005161	32
			.rodata	180988	181020	32
	lighting-app	debug+rpc	(read only)	2178777	2178809	32
			.rodata	175164	175196	32
	ota-provider-app	debug	(read only)	1946513	1946545	32
			.rodata	166987	167019	32
	ota-requestor-app	debug	(read only)	1969953	1969985	32
			.rodata	162980	163012	32
	shell	debug	(read only)	2427657	2427689	32
			.rodata	209362	209394	32
	thermostat-no-ble	arm64	(read only)	2262692	`2262708`	16
			.text	1899600	1899616	16
	tv-app	debug	(read only)	2678521	2678553	32
			.rodata	207157	207189	32

Full report (27 builds for cyw30739, efr32, esp32, k32w, linux, mbed, nrfconnect, p6, telink)

platform	target	config	section	`7172ac9`	`e249aa0`	change
cyw30739	light	cyw930739m2evb_01	(read/write)	603478	603478	0
			.app_xip_area	510576	510576	0
			.bss	75656	75656	0
			.data	596	596	0
			.rodata	0	0	0
			.text	0	0	0
	lock	cyw930739m2evb_01	(read/write)	561274	561274	0
			.app_xip_area	469900	469900	0
			.bss	74160	74160	0
			.data	560	560	0
			.rodata	0	0	0
			.text	0	0	0
	ota-requestor-no-progress-logging	cyw930739m2evb_01	(read/write)	572806	572806	0
			.app_xip_area	471784	471784	0
			.bss	83488	83488	0
			.data	500	500	0
			.rodata	0	0	0
			.text	112	112	0
efr32	lighting-app	BRD4161A	(read only)	922300	922300	0
			(read/write)	128756	128756	0
			.bss	126768	126768	0
			.data	1988	1988	0
			.text	922292	922292	0
		BRD4161A+rpc	(read only)	951128	951128	0
			(read/write)	144712	144712	0
			.bss	142544	142544	0
			.data	2168	2168	0
			.text	951120	951120	0
	window-app	BRD4161A	(read only)	852660	852660	0
			(read/write)	126720	126720	0
			.bss	124856	124856	0
			.data	1864	1864	0
			.text	852652	852652	0
esp32	all-clusters-app	c3devkit	(read only)	964156	964156	0
			(read/write)	`1393714`	`1393714`	0
			.dram0.bss	62072	62072	0
			.dram0.data	14188	14188	0
			.flash.rodata	198536	198536	0
			.flash.text	964156	964156	0
			.iram0.text	62016	62016	0
		m5stack	(read only)	1020687	1020687	0
			(read/write)	461492	461492	0
			.dram0.bss	67600	67600	0
			.dram0.data	34016	34016	0
			.flash.rodata	228040	228040	0
			.flash.text	1015303	1015303	0
			.iram0.text	123107	123107	0
k32w	light	k32w061+release	(read/write)	701120	701120	0
			.bss	77656	77656	0
			.data	1868	1868	0
			.text	615796	615796	0
	lock	k32w061+release	(read/write)	701088	701088	0
			.bss	77624	77624	0
			.data	1908	1908	0
			.text	615756	615756	0
linux	all-clusters-app	debug	(read only)	2478329	2478361	32
			(read/write)	143216	143216	0
			.bss	57312	57312	0
			.data	1264	1264	0
			.data.rel.ro	78904	78904	0
			.dynamic	592	592	0
			.got	4168	4168	0
			.init	27	27	0
			.init_array	936	936	0
			.rodata	211941	211973	32
			.text	2102914	2102914	0
	bridge-app	debug+rpc	(read only)	1753373	`1753405`	32
			(read/write)	89424	89424	0
			.bss	44456	44456	0
			.data	1952	1952	0
			.data.rel.ro	37944	37944	0
			.dynamic	592	592	0
			.got	3920	3920	0
			.init	27	27	0
			.init_array	544	544	0
			.rodata	144556	144588	32
			.text	1493605	1493605	0
	chip-tool	debug	(read only)	10163805	10166525	2720
			(read/write)	354944	354944	0
			.bss	22336	22336	0
			.data	1072	1072	0
			.data.rel.ro	325472	325472	0
			.dynamic	608	608	0
			.got	4784	4784	0
			.init	27	27	0
			.init_array	632	632	0
			.rodata	518677	518805	128
			.text	8862405	8864997	2592
	chip-tool-ipv6only	arm64	(read only)	9785084	`9786716`	1632
			(read/write)	472961	472961	0
			.bss	40625	40625	0
			.data	1128	1128	0
			.data.rel.ro	371880	371880	0
			.dynamic	560	560	0
			.got	55528	55528	0
			.init	24	24	0
			.init_array	192	192	0
			.rodata	494308	494356	48
			.text	8238692	8240276	1584
	door-lock-app	debug	(read only)	2005129	2005161	32
			(read/write)	116832	116832	0
			.bss	47584	47584	0
			.data	992	992	0
			.data.rel.ro	62856	62856	0
			.dynamic	592	592	0
			.got	4120	4120	0
			.init	27	27	0
			.init_array	664	664	0
			.rodata	180988	181020	32
			.text	1674482	1674482	0
	lighting-app	debug+rpc	(read only)	2178777	2178809	32
			(read/write)	123792	123792	0
			.bss	48864	48864	0
			.data	1472	1472	0
			.data.rel.ro	67928	67928	0
			.dynamic	608	608	0
			.got	4168	4168	0
			.init	27	27	0
			.init_array	744	744	0
			.rodata	175164	175196	32
			.text	1844594	1844594	0
	ota-provider-app	debug	(read only)	1946513	1946545	32
			(read/write)	112560	112560	0
			.bss	47456	47456	0
			.data	1256	1256	0
			.data.rel.ro	58200	58200	0
			.dynamic	608	608	0
			.got	4376	4376	0
			.init	27	27	0
			.init_array	616	616	0
			.rodata	166987	167019	32
			.text	1627810	1627810	0
	ota-requestor-app	debug	(read only)	1969953	1969985	32
			(read/write)	115592	115592	0
			.bss	48480	48480	0
			.data	1416	1416	0
			.data.rel.ro	60264	60264	0
			.dynamic	592	592	0
			.got	4168	4168	0
			.init	27	27	0
			.init_array	640	640	0
			.rodata	162980	163012	32
			.text	1654962	1654962	0
	shell	debug	(read only)	2427657	2427689	32
			(read/write)	147272	147272	0
			.bss	67240	67240	0
			.data	784	784	0
			.data.rel.ro	73536	73536	0
			.dynamic	592	592	0
			.got	4152	4152	0
			.init	27	27	0
			.init_array	920	920	0
			.rodata	209362	209394	32
			.text	2061570	2061570	0
	thermostat-no-ble	arm64	(read only)	2262692	`2262708`	16
			(read/write)	148273	148273	0
			.bss	62753	62753	0
			.data	1024	1024	0
			.data.rel.ro	77000	77000	0
			.dynamic	560	560	0
			.got	4480	4480	0
			.init	24	24	0
			.init_array	360	360	0
			.rodata	139780	139780	0
			.text	1899600	1899616	16
	tv-app	debug	(read only)	2678521	2678553	32
			(read/write)	247744	247744	0
			.bss	164416	164416	0
			.data	3104	3104	0
			.data.rel.ro	74168	74168	0
			.dynamic	592	592	0
			.got	4552	4552	0
			.init	27	27	0
			.init_array	888	888	0
			.rodata	207157	207189	32
			.text	2296514	2296514	0
mbed	lock-app	CY8CPROTO_062_4343W+release	(read only)	6224	6224	0
			(read/write)	2353636	2353636	0
			.bss	184652	184652	0
			.data	5752	5752	0
			.text	1316236	1316236	0
nrfconnect	all-clusters-app	nrf52840dk_nrf52840	(read/write)	1138947	1138947	0
			bss	142588	142588	0
			rodata	141516	141516	0
			text	780084	780084	0
p6	all-clusters-app	default	(read/write)	`2493592`	`2493592`	0
			.bss	118072	118072	0
			.data	2632	2632	0
			.text	`1451856`	`1451856`	0
	light-app	default	(read/write)	2396776	2396776	0
			.bss	111544	111544	0
			.data	2488	2488	0
			.text	1355040	1355040	0
	lock-app	default	(read/write)	`2360312`	`2360312`	0
			.bss	111288	111288	0
			.data	2448	2448	0
			.text	`1318576`	`1318576`	0
telink	lighting-app	tlsr9518adk80d	(read/write)	896954	896954	0
			bss	87444	87444	0
			noinit	37160	37160	0
			text	634304	634304	0

- Add new traces for the prepared messages for send and receive. - Add handlers to pack the data into json. Note: This is only enabled when CHIP_CONFIG_TRANSPORT_TRACE is enabled, otherwise this is a no-op.

trace: Add tracing for prepared secure messages

e249aa0

- Add new traces for the prepared messages for send and receive. - Add handlers to pack the data into json. Note: This is only enabled when CHIP_CONFIG_TRANSPORT_TRACE is enabled, otherwise this is a no-op.

boring-cyborg bot added examples transport labels Mar 23, 2022

pullapprove bot requested review from sagar-apple, saurabhst, selissia, tcarmelveilleux, tecimovic, turon, vijs, vivien-apple, wbschiller, woody-apple, xylophone21, yufengwangca and yunhanw-google March 23, 2022 13:28

pullapprove bot added the review - pending label Mar 23, 2022

bzbarsky-apple approved these changes Mar 24, 2022

View reviewed changes

andy31415 approved these changes Mar 24, 2022

View reviewed changes

pullapprove bot added review - approved and removed review - pending labels Mar 24, 2022

andy31415 merged commit dad6375 into project-chip:master Mar 24, 2022

andy31415 mentioned this pull request May 30, 2022

Add chip-trace-decoder program and get more messages logging from chip-tool and application based on examples/platform/linux #18893

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

trace: Add tracing for prepared secure messages #16565

trace: Add tracing for prepared secure messages #16565

rgoliver commented Mar 23, 2022

github-actions bot commented Mar 23, 2022 •

edited

Loading

trace: Add tracing for prepared secure messages #16565

trace: Add tracing for prepared secure messages #16565

Conversation

rgoliver commented Mar 23, 2022

Problem

Change overview

Testing

github-actions bot commented Mar 23, 2022 • edited Loading

github-actions bot commented Mar 23, 2022 •

edited

Loading