Unhelpful error log on unmarshallable ES error response

[pebrc]

cloud-on-k8s/pkg/controller/elasticsearch/client/error.go

Lines 44 to 46 in 995403b

	// Only log at the debug level since it is expected to not be able to parse all types of errors.
	// Some errors, like 408 on /_cluster/health may return a different body structure.
	log.V(1).Error(err, "Cannot parse Elasticsearch error response body")

produces errors like this:

{"log.level":"error","@timestamp":"2022-03-14T10:03:07.693Z","log.logger":"elasticsearch-client","message":"Cannot parse Elasticsearch error response body","service.version":"2.1.0+02a8d7c7","service.type":"eck","ecs.version":"1.4.0","error":"json: cannot unmarshal string into Go struct field ErrorResponse.status of type int","error.stack_trace":"github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client.newAPIError\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client/error.go:46\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client.(*baseClient).doRequest\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client/base.go:88\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client.(*baseClient).request\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client/base.go:144\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client.(*clientV6).GetClusterHealthWaitForAllEvents\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/client/v6.go:95\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.(*memoizingHealth).initialize\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/esstate.go:139\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.initOnce.func1\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/esstate.go:49\nsync.(*Once).doSlow\n\t/usr/local/go/src/sync/once.go:68\nsync.(*Once).Do\n\t/usr/local/go/src/sync/once.go:59\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.initOnce\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/esstate.go:48\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.(*memoizingHealth).Health\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/esstate.go:149\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.glob..func6\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/upgrade_predicates.go:299\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.runPredicates\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/upgrade_pods_deletion.go:250\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.applyPredicates\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/upgrade_predicates.go:168\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.(*upgradeCtx).Delete\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/upgrade_pods_deletion.go:58\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.run\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/upgrade.go:187\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.(*defaultDriver).handleUpgrades\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/upgrade.go:112\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.(*defaultDriver).reconcileNodeSpecs\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/nodes.go:203\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver.(*defaultDriver).Reconcile\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/driver/driver.go:328\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch.(*ReconcileElasticsearch).internalReconcile\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/elasticsearch_controller.go:304\ngithub.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch.(*ReconcileElasticsearch).Reconcile\n\t/go/src/github.com/elastic/cloud-on-k8s/pkg/controller/elasticsearch/elasticsearch_controller.go:188\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}

This was from an operator deployment that is running with log verbosity set to 0 so I wonder if log.Error ignores the verbosity level of the logger.

I think the error message is not helpful especially as we are expecting this error. It might even be confusing to users who might be lead to think something is wrong when it isn't

Maybe we should not log this as an error but just log the contents of the response body as an .V(1).Info level log.

[sourikghosh]

can I work on this issue?
/assign

[pebrc]

@sourikghosh apologies for the late reply. Yes, you can raise a PR with your fix against this repo.

[deepto98]

Can I pick this up, if still open?