diff --git a/BUILD.gn b/BUILD.gn index 85f7dfc9dd2208..258ea4852ff27f 100644 --- a/BUILD.gn +++ b/BUILD.gn @@ -47,12 +47,15 @@ if (current_toolchain != "${dir_pw_toolchain}/default:default") { "$dir_pw_doctor/py", "$dir_pw_env_setup/py", "$dir_pw_hdlc/py", + "$dir_pw_log:protos.python", "$dir_pw_module/py", "$dir_pw_protobuf/py", "$dir_pw_protobuf_compiler/py", "$dir_pw_rpc/py", "$dir_pw_status/py", "$dir_pw_toolchain/py", + "$dir_pw_trace/py", + "$dir_pw_trace_tokenized/py", "$dir_pw_unit_test/py", "$dir_pw_watch/py", "integrations/mobly:chip_mobly", diff --git a/config/esp32/components/chip/CMakeLists.txt b/config/esp32/components/chip/CMakeLists.txt index 94153fa20085ac..2fcfd0a899cf58 100644 --- a/config/esp32/components/chip/CMakeLists.txt +++ b/config/esp32/components/chip/CMakeLists.txt @@ -80,9 +80,11 @@ if(CONFIG_ENABLE_PW_RPC) string(APPEND chip_gn_args "import(\"//build_overrides/pigweed.gni\")\n") chip_gn_arg_append("remove_default_configs" "[\"//third_party/connectedhomeip/third_party/pigweed/repo/pw_build:cpp17\"]") chip_gn_arg_append("chip_build_pw_rpc_lib" "true") + chip_gn_arg_append("chip_build_pw_trace_lib" "true") chip_gn_arg_append("pw_log_BACKEND" "\"//third_party/connectedhomeip/third_party/pigweed/repo/pw_log_basic\"") chip_gn_arg_append("pw_assert_BACKEND" "\"//third_party/connectedhomeip/third_party/pigweed/repo/pw_assert_log\"") chip_gn_arg_append("pw_sys_io_BACKEND" "\"//third_party/connectedhomeip/examples/platform/esp32/pw_sys_io:pw_sys_io_esp32\"") + chip_gn_arg_append("pw_trace_BACKEND" "\"//third_party/connectedhomeip/third_party/pigweed/repo/pw_trace_tokenized\"") chip_gn_arg_append("dir_pw_third_party_nanopb" "\"//third_party/connectedhomeip/third_party/nanopb/repo\"") chip_gn_arg_append("pw_build_LINK_DEPS" "[\"\$dir_pw_assert:impl\", \"\$dir_pw_log:impl\"]") endif() diff --git a/config/esp32/components/chip/component.mk b/config/esp32/components/chip/component.mk index 21339e3bc3f95c..6b8714b1db620e 100644 --- a/config/esp32/components/chip/component.mk +++ b/config/esp32/components/chip/component.mk @@ -140,6 +140,7 @@ endif echo "pw_log_BACKEND = \"//third_party/connectedhomeip/third_party/pigweed/repo/pw_log_basic\"" >> $(OUTPUT_DIR)/args.gn ;\ echo "pw_assert_BACKEND = \"//third_party/connectedhomeip/third_party/pigweed/repo/pw_assert_log\"" >> $(OUTPUT_DIR)/args.gn ;\ echo "pw_sys_io_BACKEND = \"//third_party/connectedhomeip/examples/platform/esp32/pw_sys_io:pw_sys_io_esp32\"" >> $(OUTPUT_DIR)/args.gn ;\ + echo "pw_trace_BACKEND = \"//third_party/connectedhomeip/third_party/pigweed/repo/pw_trace_tokenized\"" >> $(OUTPUT_DIR)/args.gn ;\ echo "dir_pw_third_party_nanopb = \"//third_party/connectedhomeip/third_party/nanopb/repo\"" >>$(OUTPUT_DIR)/args.gn ;\ fi if [[ "$(CONFIG_ENABLE_CHIP_SHELL)" = "y" ]]; then \ diff --git a/examples/platform/esp32/Rpc.cpp b/examples/platform/esp32/Rpc.cpp index 9286191dc4eeca..a0fa1530731c6c 100644 --- a/examples/platform/esp32/Rpc.cpp +++ b/examples/platform/esp32/Rpc.cpp @@ -53,6 +53,7 @@ #endif // defined(PW_RPC_LOCKING_SERVICE) && PW_RPC_LOCKING_SERVICE #if defined(PW_RPC_TRACING_SERVICE) && PW_RPC_TRACING_SERVICE +#define PW_TRACE_BUFFER_SIZE_BYTES 1024 #include "pw_trace/trace.h" #include "pw_trace_tokenized/trace_rpc_service_nanopb.h" @@ -167,6 +168,7 @@ void RegisterServices(pw::rpc::Server & server) #if defined(PW_RPC_TRACING_SERVICE) && PW_RPC_TRACING_SERVICE server.RegisterService(trace_service); + PW_TRACE_SET_ENABLED(true); #endif // defined(PW_RPC_TRACING_SERVICE) && PW_RPC_TRACING_SERVICE } diff --git a/examples/platform/nrfconnect/Rpc.cpp b/examples/platform/nrfconnect/Rpc.cpp index 580c925d883465..23feea30b8c552 100644 --- a/examples/platform/nrfconnect/Rpc.cpp +++ b/examples/platform/nrfconnect/Rpc.cpp @@ -46,6 +46,7 @@ LOG_MODULE_DECLARE(app); #endif // defined(PW_RPC_LOCKING_SERVICE) && PW_RPC_LOCKING_SERVICE #if defined(PW_RPC_TRACING_SERVICE) && PW_RPC_TRACING_SERVICE +#define PW_TRACE_BUFFER_SIZE_BYTES 1024 #include "pw_trace/trace.h" #include "pw_trace_tokenized/trace_rpc_service_nanopb.h" @@ -155,6 +156,7 @@ void RegisterServices(pw::rpc::Server & server) #if defined(PW_RPC_TRACING_SERVICE) && PW_RPC_TRACING_SERVICE server.RegisterService(trace_service); + PW_TRACE_SET_ENABLED(true); #endif // defined(PW_RPC_TRACING_SERVICE) && PW_RPC_TRACING_SERVICE } diff --git a/src/protocols/secure_channel/BUILD.gn b/src/protocols/secure_channel/BUILD.gn index 5b4c9ef9580cd2..ed9bf68b9dd28e 100644 --- a/src/protocols/secure_channel/BUILD.gn +++ b/src/protocols/secure_channel/BUILD.gn @@ -29,5 +29,6 @@ static_library("secure_channel") { "${chip_root}/src/lib/support", "${chip_root}/src/messaging", "${chip_root}/src/system", + "${chip_root}/src/trace", ] } diff --git a/src/protocols/secure_channel/CASESession.cpp b/src/protocols/secure_channel/CASESession.cpp index 90a0326d5a3cbe..15df65fa573855 100644 --- a/src/protocols/secure_channel/CASESession.cpp +++ b/src/protocols/secure_channel/CASESession.cpp @@ -38,6 +38,7 @@ #include #include #include +#include #include #include @@ -225,6 +226,7 @@ CHIP_ERROR CASESession::EstablishSession(const Transport::PeerAddress peerAddres uint16_t localSessionId, ExchangeContext * exchangeCtxt, SessionEstablishmentDelegate * delegate, Optional mrpConfig) { + TRACE_EVENT_SCOPE("EstablishSession", "CASESession"); CHIP_ERROR err = CHIP_NO_ERROR; // Return early on error here, as we have not initialized any state yet @@ -303,6 +305,7 @@ CHIP_ERROR CASESession::DeriveSecureSession(CryptoContext & session, CryptoConte CHIP_ERROR CASESession::SendSigma1() { + TRACE_EVENT_SCOPE("SendSigma1", "CASESession"); const size_t mrpParamsSize = mLocalMRPConfig.HasValue() ? TLV::EstimateStructOverhead(sizeof(uint16_t), sizeof(uint16_t)) : 0; size_t data_len = TLV::EstimateStructOverhead(kSigmaParamRandomNumberSize, // initiatorRandom sizeof(uint16_t), // initiatorSessionId, @@ -385,6 +388,7 @@ CHIP_ERROR CASESession::SendSigma1() CHIP_ERROR CASESession::HandleSigma1_and_SendSigma2(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandleSigma1_and_SendSigma2", "CASESession"); ReturnErrorOnFailure(HandleSigma1(std::move(msg))); return CHIP_NO_ERROR; @@ -392,6 +396,7 @@ CHIP_ERROR CASESession::HandleSigma1_and_SendSigma2(System::PacketBufferHandle & CHIP_ERROR CASESession::HandleSigma1(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandleSigma1", "CASESession"); CHIP_ERROR err = CHIP_NO_ERROR; System::PacketBufferTLVReader tlvReader; @@ -469,6 +474,7 @@ CHIP_ERROR CASESession::HandleSigma1(System::PacketBufferHandle && msg) CHIP_ERROR CASESession::SendSigma2Resume(const ByteSpan & initiatorRandom) { + TRACE_EVENT_SCOPE("SendSigma2Resume", "CASESession"); const size_t mrpParamsSize = mLocalMRPConfig.HasValue() ? TLV::EstimateStructOverhead(sizeof(uint16_t), sizeof(uint16_t)) : 0; size_t max_sigma2_resume_data_len = TLV::EstimateStructOverhead(kCASEResumptionIDSize, CHIP_CRYPTO_AEAD_MIC_LENGTH_BYTES, sizeof(uint16_t), mrpParamsSize); @@ -519,6 +525,7 @@ CHIP_ERROR CASESession::SendSigma2Resume(const ByteSpan & initiatorRandom) CHIP_ERROR CASESession::SendSigma2() { + TRACE_EVENT_SCOPE("SendSigma2", "CASESession"); VerifyOrReturnError(mFabricInfo != nullptr, CHIP_ERROR_INCORRECT_STATE); ByteSpan icaCert; @@ -649,6 +656,7 @@ CHIP_ERROR CASESession::SendSigma2() CHIP_ERROR CASESession::HandleSigma2Resume(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandleSigma2Resume", "CASESession"); CHIP_ERROR err = CHIP_NO_ERROR; System::PacketBufferTLVReader tlvReader; TLV::TLVType containerType = TLV::kTLVType_Structure; @@ -715,6 +723,7 @@ CHIP_ERROR CASESession::HandleSigma2Resume(System::PacketBufferHandle && msg) CHIP_ERROR CASESession::HandleSigma2_and_SendSigma3(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandleSigma2_and_SendSigma3", "CASESession"); ReturnErrorOnFailure(HandleSigma2(std::move(msg))); ReturnErrorOnFailure(SendSigma3()); @@ -723,6 +732,7 @@ CHIP_ERROR CASESession::HandleSigma2_and_SendSigma3(System::PacketBufferHandle & CHIP_ERROR CASESession::HandleSigma2(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandleSigma2", "CASESession"); CHIP_ERROR err = CHIP_NO_ERROR; System::PacketBufferTLVReader tlvReader; TLV::TLVReader decryptedDataTlvReader; @@ -876,6 +886,7 @@ CHIP_ERROR CASESession::HandleSigma2(System::PacketBufferHandle && msg) CHIP_ERROR CASESession::SendSigma3() { + TRACE_EVENT_SCOPE("SendSigma3", "CASESession"); CHIP_ERROR err = CHIP_NO_ERROR; MutableByteSpan messageDigestSpan(mMessageDigest); @@ -1010,6 +1021,7 @@ CHIP_ERROR CASESession::SendSigma3() CHIP_ERROR CASESession::HandleSigma3(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandleSigma3", "CASESession"); CHIP_ERROR err = CHIP_NO_ERROR; MutableByteSpan messageDigestSpan(mMessageDigest); System::PacketBufferTLVReader tlvReader; diff --git a/src/protocols/secure_channel/PASESession.cpp b/src/protocols/secure_channel/PASESession.cpp index 3f1d29cadc146e..260dc47e8d7990 100644 --- a/src/protocols/secure_channel/PASESession.cpp +++ b/src/protocols/secure_channel/PASESession.cpp @@ -45,6 +45,7 @@ #include #include #include +#include #include namespace chip { @@ -218,6 +219,7 @@ CHIP_ERROR PASESession::Init(uint16_t mySessionId, uint32_t setupCode, SessionEs CHIP_ERROR PASESession::ComputePASEVerifier(uint32_t setUpPINCode, uint32_t pbkdf2IterCount, const ByteSpan & salt, PASEVerifier & verifier) { + TRACE_EVENT_SCOPE("ComputePASEVerifier", "PASESession"); ReturnErrorCodeIf(salt.empty(), CHIP_ERROR_INVALID_ARGUMENT); ReturnErrorCodeIf(salt.data() == nullptr, CHIP_ERROR_INVALID_ARGUMENT); ReturnErrorCodeIf(setUpPINCode >= (1 << kSetupPINCodeFieldLengthInBits), CHIP_ERROR_INVALID_ARGUMENT); @@ -246,6 +248,7 @@ CHIP_ERROR PASESession::GeneratePASEVerifier(PASEVerifier & verifier, uint32_t p CHIP_ERROR PASESession::SetupSpake2p(uint32_t pbkdf2IterCount, const ByteSpan & salt) { + TRACE_EVENT_SCOPE("SetupSpake2p", "PASESession"); uint8_t context[kSHA256_Hash_Length] = { 0, }; @@ -329,6 +332,7 @@ CHIP_ERROR PASESession::Pair(const Transport::PeerAddress peerAddress, uint32_t Optional mrpConfig, Messaging::ExchangeContext * exchangeCtxt, SessionEstablishmentDelegate * delegate) { + TRACE_EVENT_SCOPE("Pair", "PASESession"); ReturnErrorCodeIf(exchangeCtxt == nullptr, CHIP_ERROR_INVALID_ARGUMENT); CHIP_ERROR err = Init(mySessionId, peerSetUpPINCode, delegate); SuccessOrExit(err); @@ -379,6 +383,7 @@ CHIP_ERROR PASESession::DeriveSecureSession(CryptoContext & session, CryptoConte CHIP_ERROR PASESession::SendPBKDFParamRequest() { + TRACE_EVENT_SCOPE("SendPBKDFParamRequest", "PASESession"); ReturnErrorOnFailure(DRBG_get_bytes(mPBKDFLocalRandomData, sizeof(mPBKDFLocalRandomData))); const size_t mrpParamsSize = mLocalMRPConfig.HasValue() ? TLV::EstimateStructOverhead(sizeof(uint16_t), sizeof(uint16_t)) : 0; @@ -424,6 +429,7 @@ CHIP_ERROR PASESession::SendPBKDFParamRequest() CHIP_ERROR PASESession::HandlePBKDFParamRequest(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandlePBKDFParamRequest", "PASESession"); CHIP_ERROR err = CHIP_NO_ERROR; System::PacketBufferTLVReader tlvReader; @@ -483,6 +489,7 @@ CHIP_ERROR PASESession::HandlePBKDFParamRequest(System::PacketBufferHandle && ms CHIP_ERROR PASESession::SendPBKDFParamResponse(ByteSpan initiatorRandom, bool initiatorHasPBKDFParams) { + TRACE_EVENT_SCOPE("SendPBKDFParamResponse", "PASESession"); ReturnErrorOnFailure(DRBG_get_bytes(mPBKDFLocalRandomData, sizeof(mPBKDFLocalRandomData))); const size_t mrpParamsSize = mLocalMRPConfig.HasValue() ? TLV::EstimateStructOverhead(sizeof(uint16_t), sizeof(uint16_t)) : 0; @@ -543,7 +550,7 @@ CHIP_ERROR PASESession::SendPBKDFParamResponse(ByteSpan initiatorRandom, bool in CHIP_ERROR PASESession::HandlePBKDFParamResponse(System::PacketBufferHandle && msg) { - + TRACE_EVENT_SCOPE("HandlePBKDFParamResponse", "PASESession"); CHIP_ERROR err = CHIP_NO_ERROR; System::PacketBufferTLVReader tlvReader; @@ -633,6 +640,7 @@ CHIP_ERROR PASESession::HandlePBKDFParamResponse(System::PacketBufferHandle && m CHIP_ERROR PASESession::SendMsg1() { + TRACE_EVENT_SCOPE("SendMsg1", "PASESession"); const size_t max_msg_len = TLV::EstimateStructOverhead(kMAX_Point_Length); System::PacketBufferHandle msg = System::PacketBufferHandle::New(max_msg_len); VerifyOrReturnError(!msg.IsNull(), CHIP_ERROR_NO_MEMORY); @@ -667,6 +675,7 @@ CHIP_ERROR PASESession::SendMsg1() CHIP_ERROR PASESession::HandleMsg1_and_SendMsg2(System::PacketBufferHandle && msg1) { + TRACE_EVENT_SCOPE("HandleMsg1_and_SendMsg2", "PASESession"); CHIP_ERROR err = CHIP_NO_ERROR; uint8_t Y[kMAX_Point_Length]; @@ -736,6 +745,7 @@ CHIP_ERROR PASESession::HandleMsg1_and_SendMsg2(System::PacketBufferHandle && ms CHIP_ERROR PASESession::HandleMsg2_and_SendMsg3(System::PacketBufferHandle && msg2) { + TRACE_EVENT_SCOPE("HandleMsg2_and_SendMsg3", "PASESession"); CHIP_ERROR err = CHIP_NO_ERROR; uint8_t verifier[kMAX_Hash_Length]; @@ -811,6 +821,7 @@ CHIP_ERROR PASESession::HandleMsg2_and_SendMsg3(System::PacketBufferHandle && ms CHIP_ERROR PASESession::HandleMsg3(System::PacketBufferHandle && msg) { + TRACE_EVENT_SCOPE("HandleMsg3", "PASESession"); CHIP_ERROR err = CHIP_NO_ERROR; ChipLogDetail(SecureChannel, "Received spake2p msg3"); diff --git a/src/trace/BUILD.gn b/src/trace/BUILD.gn new file mode 100644 index 00000000000000..546107ad45ce67 --- /dev/null +++ b/src/trace/BUILD.gn @@ -0,0 +1,28 @@ +# Copyright (c) 2022 Project CHIP Authors +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import("//build_overrides/pigweed.gni") + +declare_args() { + chip_build_pw_trace_lib = false +} + +source_set("trace") { + sources = [ "trace.h" ] + + if (chip_build_pw_trace_lib) { + cflags = [ "-DPW_TRACE_BACKEND_SET=1" ] + public_deps = [ "${dir_pigweed}/pw_trace" ] + } +} diff --git a/src/trace/trace.h b/src/trace/trace.h new file mode 100644 index 00000000000000..f6e23134d0191a --- /dev/null +++ b/src/trace/trace.h @@ -0,0 +1,65 @@ +/* + * + * Copyright (c) 2022 Project CHIP Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#pragma once + +#if defined(PW_TRACE_BACKEND_SET) && PW_TRACE_BACKEND_SET + +#include + +#define TRACE_EVENT_INSTANT(...) PW_TRACE_INSTANT(__VA_ARGS__) +#define TRACE_EVENT_INSTANT_FLAG(...) PW_TRACE_INSTANT_FLAG(__VA_ARGS__) +#define TRACE_EVENT_INSTANT_DATA(...) PW_TRACE_INSTANT_DATA(__VA_ARGS__) +#define TRACE_EVENT_INSTANT_DATA_FLAG(...) PW_TRACE_INSTANT_DATA_FLAG(__VA_ARGS__) +#define TRACE_EVENT_START(...) PW_TRACE_START(__VA_ARGS__) +#define TRACE_EVENT_START_FLAG(...) PW_TRACE_START_FLAG(__VA_ARGS__) +#define TRACE_EVENT_START_DATA(...) PW_TRACE_START_DATA(__VA_ARGS__) +#define TRACE_EVENT_START_DATA_FLAG(...) PW_TRACE_START_DATA_FLAG(__VA_ARGS__) +#define TRACE_EVENT_END(...) PW_TRACE_END(__VA_ARGS__) +#define TRACE_EVENT_END_FLAG(...) PW_TRACE_END_FLAG(__VA_ARGS__) +#define TRACE_EVENT_END_DATA(...) PW_TRACE_END_DATA(__VA_ARGS__) +#define TRACE_EVENT_END_DATA_FLAG(...) PW_TRACE_END_DATA_FLAG(__VA_ARGS__) +#define TRACE_EVENT_SCOPE(...) PW_TRACE_SCOPE(__VA_ARGS__) +#define TRACE_EVENT_SCOPE_FLAG(...) PW_TRACE_SCOPE_FLAG(__VA_ARGS__) +#define TRACE_EVENT_FUNCTION(...) PW_TRACE_FUNCTION(__VA_ARGS__) +#define TRACE_EVENT_FUNCTION_FLAG(...) PW_TRACE_FUNCTION_FLAG(__VA_ARGS__) + +#else // defined(PW_TRACE_BACKEND_SET) && PW_TRACE_BACKEND_SET + +#define _TRACE_EVENT_DISABLE(...) \ + do \ + { \ + } while (0) + +#define TRACE_EVENT_INSTANT(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_INSTANT_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_INSTANT_DATA(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_INSTANT_DATA_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_START(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_START_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_START_DATA(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_START_DATA_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_END(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_END_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_END_DATA(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_END_DATA_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_SCOPE(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_SCOPE_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_FUNCTION(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) +#define TRACE_EVENT_FUNCTION_FLAG(...) _TRACE_EVENT_DISABLE(__VA_ARGS__) + +#endif // defined(PW_TRACE_BACKEND_SET) && PW_TRACE_BACKEND_SET