From 387cc0a49f5c8921c13f7021c3503b5f7fee89ad Mon Sep 17 00:00:00 2001 From: Brian Flad Date: Wed, 4 May 2022 09:49:32 -0400 Subject: [PATCH 1/2] internal/proto6server: Ensure logging.InitContext is called before any RPC logic Verified with terraform-provider-corner. Creating unit testing for this setup requires something like https://github.com/hashicorp/terraform-plugin-log/issues/61 upstream. Previously: ```text 2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Calling provider defined Provider GetResources: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange 2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Called provider defined Provider GetResources: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange 2022-05-03T13:38:24.417-0400 [DEBUG] sdk.framework: Calling provider defined ResourceType GetSchema: new_logger_warning="This log was generated by an SDK subsystem logger that wasn't created before being used. Use tflog.NewSubsystem to create this logger before it is used." tf_provider_addr=registry.terraform.io/hashicorp/framework tf_req_id=44608b15-0686-e9f9-1d17-56ca3c63b336 tf_resource_type=framework_user tf_rpc=ApplyResourceChange ``` Now: ```text 2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Calling provider defined Provider GetResources 2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Called provider defined Provider GetResources 2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Calling provider defined ResourceType GetSchema 2022-05-04T09:21:20.515-0400 [DEBUG] sdk.framework: Called provider defined ResourceType GetSchema ``` --- .changelog/pending.txt | 3 +++ internal/proto6server/serve.go | 10 ++++++++++ internal/proto6server/serve_import.go | 1 + 3 files changed, 14 insertions(+) create mode 100644 .changelog/pending.txt diff --git a/.changelog/pending.txt b/.changelog/pending.txt new file mode 100644 index 000000000..9fddfdb30 --- /dev/null +++ b/.changelog/pending.txt @@ -0,0 +1,3 @@ +```release-note:bug +all: Prevented `This log was generated by an SDK subsystem logger that wasn't created before being used.` warning messages in logging +``` diff --git a/internal/proto6server/serve.go b/internal/proto6server/serve.go index 35c218bac..a906f7d8c 100644 --- a/internal/proto6server/serve.go +++ b/internal/proto6server/serve.go @@ -107,6 +107,7 @@ func (r getProviderSchemaResponse) toTfprotov6() *tfprotov6.GetProviderSchemaRes func (s *Server) GetProviderSchema(ctx context.Context, _ *tfprotov6.GetProviderSchemaRequest) (*tfprotov6.GetProviderSchemaResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := new(getProviderSchemaResponse) s.getProviderSchema(ctx, resp) @@ -246,6 +247,7 @@ func (r validateProviderConfigResponse) toTfprotov6() *tfprotov6.ValidateProvide func (s *Server) ValidateProviderConfig(ctx context.Context, req *tfprotov6.ValidateProviderConfigRequest) (*tfprotov6.ValidateProviderConfigResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &validateProviderConfigResponse{ // This RPC allows a modified configuration to be returned. This was // previously used to allow a "required" provider attribute (as defined @@ -359,6 +361,7 @@ func (r configureProviderResponse) toTfprotov6() *tfprotov6.ConfigureProviderRes func (s *Server) ConfigureProvider(ctx context.Context, req *tfprotov6.ConfigureProviderRequest) (*tfprotov6.ConfigureProviderResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &configureProviderResponse{} s.configureProvider(ctx, req, resp) @@ -415,6 +418,7 @@ func (r validateResourceConfigResponse) toTfprotov6() *tfprotov6.ValidateResourc func (s *Server) ValidateResourceConfig(ctx context.Context, req *tfprotov6.ValidateResourceConfigRequest) (*tfprotov6.ValidateResourceConfigResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &validateResourceConfigResponse{} s.validateResourceConfig(ctx, req, resp) @@ -543,6 +547,7 @@ func (r upgradeResourceStateResponse) toTfprotov6() *tfprotov6.UpgradeResourceSt func (s *Server) UpgradeResourceState(ctx context.Context, req *tfprotov6.UpgradeResourceStateRequest) (*tfprotov6.UpgradeResourceStateResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &upgradeResourceStateResponse{} s.upgradeResourceState(ctx, req, resp) @@ -773,6 +778,7 @@ func (r readResourceResponse) toTfprotov6() *tfprotov6.ReadResourceResponse { func (s *Server) ReadResource(ctx context.Context, req *tfprotov6.ReadResourceRequest) (*tfprotov6.ReadResourceResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &readResourceResponse{} s.readResource(ctx, req, resp) @@ -919,6 +925,7 @@ func (r planResourceChangeResponse) toTfprotov6() *tfprotov6.PlanResourceChangeR func (s *Server) PlanResourceChange(ctx context.Context, req *tfprotov6.PlanResourceChangeRequest) (*tfprotov6.PlanResourceChangeResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &planResourceChangeResponse{} s.planResourceChange(ctx, req, resp) @@ -1243,6 +1250,7 @@ func normaliseRequiresReplace(ctx context.Context, rs []*tftypes.AttributePath) func (s *Server) ApplyResourceChange(ctx context.Context, req *tfprotov6.ApplyResourceChangeRequest) (*tfprotov6.ApplyResourceChangeResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &applyResourceChangeResponse{ // default to the prior state, so the state won't change unless // we choose to change it @@ -1538,6 +1546,7 @@ func (r validateDataResourceConfigResponse) toTfprotov6() *tfprotov6.ValidateDat func (s *Server) ValidateDataResourceConfig(ctx context.Context, req *tfprotov6.ValidateDataResourceConfigRequest) (*tfprotov6.ValidateDataResourceConfigResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &validateDataResourceConfigResponse{} s.validateDataResourceConfig(ctx, req, resp) @@ -1666,6 +1675,7 @@ func (r readDataSourceResponse) toTfprotov6() *tfprotov6.ReadDataSourceResponse func (s *Server) ReadDataSource(ctx context.Context, req *tfprotov6.ReadDataSourceRequest) (*tfprotov6.ReadDataSourceResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &readDataSourceResponse{} s.readDataSource(ctx, req, resp) diff --git a/internal/proto6server/serve_import.go b/internal/proto6server/serve_import.go index 6bb1ffdd5..57eb0a3e3 100644 --- a/internal/proto6server/serve_import.go +++ b/internal/proto6server/serve_import.go @@ -152,6 +152,7 @@ func (s *Server) importResourceState(ctx context.Context, req *tfprotov6.ImportR // ImportResourceState satisfies the tfprotov6.ProviderServer interface. func (s *Server) ImportResourceState(ctx context.Context, req *tfprotov6.ImportResourceStateRequest) (*tfprotov6.ImportResourceStateResponse, error) { ctx = s.registerContext(ctx) + ctx = logging.InitContext(ctx) resp := &importResourceStateResponse{} s.importResourceState(ctx, req, resp) From 0af5720497f3d7f1d367eca9e1e3df912a4970bb Mon Sep 17 00:00:00 2001 From: Brian Flad Date: Wed, 4 May 2022 10:02:32 -0400 Subject: [PATCH 2/2] Update CHANGELOG for #314 --- .changelog/{pending.txt => 314.txt} | 0 1 file changed, 0 insertions(+), 0 deletions(-) rename .changelog/{pending.txt => 314.txt} (100%) diff --git a/.changelog/pending.txt b/.changelog/314.txt similarity index 100% rename from .changelog/pending.txt rename to .changelog/314.txt