Improve component init error logs and metrics #4975

addjuarez · 2022-08-04T19:13:22Z

Description

Added a componentName tag to the dapr_runtime_component_init_fail_total metric. The metric should now be produced when init failures are logged.

Also have standardized the component failure error logging for creation/init stages. All component init/create errors should now be logged.

Also removed some redundant logging of errors.

A new error type InitErrors was created and was modeled after custom etag errors. We have for initError codes and have a standardized format for error messages.
The new error message will look like :
(InitComponentFailure): initialization error occurred for statestore2 (state.redis/v1): init timeout for component statestore2 exceeded after 5s"
The new error codes.

InitComponetFailure : Any component failures to initialize or complete their init() method.
InitFailure : Any non component failures like actor init failures
CreateComponentFailure : component failed to be added to the registry

Issue reference

Part of the work involved with this.
dapr/components-contrib#1752

Checklist

Please make sure you've completed the relevant tasks for this PR, out of the following list:

Code compiles correctly
Created/updated tests
Unit tests passing
End-to-end tests passing
Extended the documentation / Created issue in the https://github.com/dapr/docs/ repo: dapr/docs#[issue number]
Specification has been updated / Created issue in the https://github.com/dapr/docs/ repo: dapr/docs#[issue number]
Provided sample for the feature / Created issue in the https://github.com/dapr/docs/ repo: dapr/docs#[issue number]

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

codecov · 2022-08-04T19:31:27Z

Codecov Report

Merging #4975 (c38343a) into master (29233c6) will decrease coverage by 0.03%.
The diff coverage is 46.60%.

@@            Coverage Diff             @@
##           master    #4975      +/-   ##
==========================================
- Coverage   65.47%   65.44%   -0.04%     
==========================================
  Files         113      114       +1     
  Lines       12723    12735      +12     
==========================================
+ Hits         8331     8334       +3     
- Misses       3809     3816       +7     
- Partials      583      585       +2

Impacted Files	Coverage Δ
pkg/runtime/runtime.go	`67.62% <40.69%> (-0.12%)`	⬇️
pkg/diagnostics/service_monitoring.go	`49.23% <50.00%> (ø)`
pkg/http/api.go	`79.53% <66.66%> (+0.01%)`	⬆️
pkg/runtime/initError.go	`71.42% <71.42%> (ø)`
pkg/grpc/api.go	`72.85% <100.00%> (-0.09%)`	⬇️
pkg/actors/internal/placement.go	`87.56% <0.00%> (-1.56%)`	⬇️

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

…initLogging

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

berndverst · 2022-08-05T17:54:14Z

For standardizing the error - what if instead we created a new error type DaprComponentInitError or something like that and change the Init interface to return that. And then we update the runtime to just log that error if Init returns an error of this type.

Creating a new error type and expecting this in the return is a much more guaranteed way to keep things consistent going forward. Nothing prevents a new component from failing to return the right error type with your proposal here. This puts unnecessary burden on approvers and maintainers to ensure Init errors are consistent.

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

…initLogging

Signed-off-by: addjuarez <addiajuarez@gmail.com>

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

…initLogging

artursouza · 2022-08-16T20:36:09Z

pkg/runtime/runtime.go

@@ -1356,18 +1356,18 @@ func (a *DaprRuntime) isAppSubscribedToBinding(binding string) bool {
 func (a *DaprRuntime) initInputBinding(c components_v1alpha1.Component) error {
 	binding, err := a.bindingsRegistry.CreateInputBinding(c.Spec.Type, c.Spec.Version)
 	if err != nil {
-		log.Warnf("failed to create input binding %s (%s/%s): %s", c.ObjectMeta.Name, c.Spec.Type, c.Spec.Version, err)


Any reason you removed this logging?

The error is log multiple times and will eventually get captured here. https://github.com/dapr/dapr/blob/master/pkg/runtime/runtime.go#L2158

artursouza · 2022-08-16T20:36:17Z

pkg/runtime/runtime.go

-		log.Errorf("failed to init input binding %s (%s/%s): %s", c.ObjectMeta.Name, c.Spec.Type, c.Spec.Version, err)
-		diag.DefaultMonitoring.ComponentInitFailed(c.Spec.Type, "init")
-		return err
+		diag.DefaultMonitoring.ComponentInitFailed(c.Spec.Type, "init", c.ObjectMeta.Name)


The error is log multiple times and will eventually get captured here. https://github.com/dapr/dapr/blob/master/pkg/runtime/runtime.go#L2158
Can add it back but it seemed redundant to print the same message multiple times

artursouza · 2022-08-16T20:36:25Z

pkg/runtime/runtime.go

-		log.Warnf("failed to create output binding %s (%s/%s): %s", c.ObjectMeta.Name, c.Spec.Type, c.Spec.Version, err)
-		diag.DefaultMonitoring.ComponentInitFailed(c.Spec.Type, "creation")
-		return err
+		diag.DefaultMonitoring.ComponentInitFailed(c.Spec.Type, "creation", c.ObjectMeta.Name)


Answered above

artursouza · 2022-08-16T20:37:58Z

pkg/runtime/runtime.go

-		log.Warnf("failed to init secret store %s/%s named %s: %s", c.Spec.Type, c.Spec.Version, c.ObjectMeta.Name, err)
-		diag.DefaultMonitoring.ComponentInitFailed(c.Spec.Type, "init")
-		return err
+		diag.DefaultMonitoring.ComponentInitFailed(c.Spec.Type, "init", c.ObjectMeta.Name)


Are these breaking changes? The metrics are part of the contracts and should be compatible, it means that someone with alerts on the existing metrics should not have to change their alerts when they upgrade to this version.

These should not be breaking changes, I have validated that our dapr grafana dashboards are able to still recieve this metric and trigger alerts unchanged.

artursouza · 2022-08-16T20:41:44Z

pkg/runtime/initError.go

+type InitErrorKind string
+
+const (
+	InitFailure            InitErrorKind = "InitFailure"


If we want these to be printed out, we should agree if these should be app caps, camel case or pascal case. Last but not least, we should agree on these error types since these become contractual.

I personally think these should be ALL_CAPS and we can keep these failure types here.

/cc @yaron2

I agree on ALL_CAPS. cc @daixiang0

I agree on ALL_CAPS as well.

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

…initLogging

ItalyPaleAle · 2022-08-19T20:32:54Z

pkg/runtime/initError.go

+
+func (e *InitError) Error() string {
+	if e.entity == "" {
+		return fmt.Sprintf("(%s): %s", e.kind, e.err)


Use square brackets for e.kind please

artursouza · 2022-08-19T20:32:58Z

pkg/runtime/initError.go

+
+func (e *InitError) Error() string {
+	if e.entity == "" {
+		return fmt.Sprintf("(%s): %s", e.kind, e.err)


"[ ]" is better.

artursouza · 2022-08-19T20:33:24Z

pkg/runtime/initError.go

+		return fmt.Sprintf("(%s): %s", e.kind, e.err)
+	}
+
+	return fmt.Sprintf("(%s): initialization error occurred for %s: %s", e.kind, e.entity, e.err)


"[ ]" is better.

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

* master: (134 commits) Record metric for service updates (dapr#5114) chore: remove duplicate word in comments (dapr#5099) Run e2e tests in previous version of K8s on AKS to see if it's breaking Windows tests (dapr#5104) add {namespace} option to set consumerID Add tracing passthrough for bindings (dapr#5049) Improve component init error logs and metrics (dapr#4975) Improvements to E2E test apps (dapr#5042) Fix component name for aws dynamodb (dapr#5095) Fix perf tests not building (dapr#5096) Fix missing components in Metadata API result. (dapr#5052) Fixed log message (dapr#5088) Disable IPFS binding for now (dapr#5092) optimize/concurrency: pubsub concurrency map writes in runtime unit test. (dapr#5086) Configuration API response to use dictionaries - based on PR dapr#4695 (dapr#5083) correct compile error correct checking for actors with same id fix type error in print fix typo add log when actor start time and end time is not expected Components auto-registration (dapr#5062) ... Signed-off-by: zhangchao <zchao9100@gmail.com> # Conflicts: # go.mod # pkg/grpc/api.go # pkg/grpc/api_test.go # pkg/http/api.go # pkg/runtime/runtime.go

addjuarez added 5 commits July 29, 2022 10:14

Add component name tag to init fail metric

485f1e4

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Change component init error logging

bff862f

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Change component timeout error log

9aca418

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Change component init/creation error logs

c899862

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Remove space

874f000

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

addjuarez added 4 commits August 4, 2022 15:00

Merge branch 'master' into initLogging

ced5c3e

add subscription errors

b17977c

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Merge branch 'initLogging' of https://github.com/addjuarez/dapr into …

2bd03fa

…initLogging

remove extra log

a35a892

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

addjuarez and others added 5 commits August 10, 2022 14:53

Add initError Type

5b53bc9

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Typo

f28c28e

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Merge branch 'master' into initLogging

f76c915

Merge branch 'initLogging' of https://github.com/addjuarez/dapr into …

0710979

…initLogging

linter

ce578aa

Signed-off-by: addjuarez <addiajuarez@gmail.com>

addjuarez marked this pull request as ready for review August 11, 2022 14:22

addjuarez requested review from a team as code owners August 11, 2022 14:22

addjuarez marked this pull request as draft August 11, 2022 18:35

addjuarez added 5 commits August 12, 2022 11:52

merge master

d0e2570

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

fix merge

edff586

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

alter error

31d7793

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Merge branch 'master' into initLogging

e67aca0

Merge branch 'initLogging' of https://github.com/addjuarez/dapr into …

6939f91

…initLogging

artursouza suggested changes Aug 16, 2022

View reviewed changes

artursouza reviewed Aug 16, 2022

View reviewed changes

Merge branch 'master' into initLogging

903c292

addjuarez marked this pull request as ready for review August 19, 2022 03:09

uppercase codes

415ee3a

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

addjuarez added 2 commits August 19, 2022 14:27

Merge branch 'initLogging' of https://github.com/addjuarez/dapr into …

bb63234

…initLogging

Merge branch 'master' into initLogging

94170a7

ItalyPaleAle reviewed Aug 19, 2022

View reviewed changes

artursouza reviewed Aug 19, 2022

View reviewed changes

addjuarez and others added 5 commits August 19, 2022 16:13

brackets

96e4f01

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

merge master

94dfac6

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

typo

0c49b97

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

conflicts

5d3df12

Signed-off-by: Addison Juarez <adjuarez@microsoft.com>

Merge branch 'master' into initLogging

f316ede

artursouza approved these changes Aug 23, 2022

View reviewed changes

artursouza and others added 2 commits August 23, 2022 13:35

Merge branch 'master' into initLogging

83c7cbe

Merge branch 'master' into initLogging

c38343a

halspang approved these changes Aug 26, 2022

View reviewed changes

Merge branch 'master' into initLogging

4d10b84

artursouza merged commit 25f74fd into dapr:master Aug 30, 2022

addjuarez deleted the initLogging branch October 19, 2022 21:16

addjuarez restored the initLogging branch October 19, 2022 21:17

Improve component init error logs and metrics #4975

Improve component init error logs and metrics #4975

Uh oh!

Conversation

addjuarez commented Aug 4, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Issue reference

Checklist

Uh oh!

codecov bot commented Aug 4, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

berndverst commented Aug 5, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

artursouza Aug 19, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

addjuarez commented Aug 4, 2022 •

edited

Loading

codecov bot commented Aug 4, 2022 •

edited

Loading

artursouza Aug 19, 2022 •

edited

Loading