Skip to content

Conversation

@jaypipes
Copy link
Collaborator

@jaypipes jaypipes commented Jun 17, 2021

Our debug-level logging wasn't particularly verbose or informative. This
patch adds a number of debug-level log messages into the core reconciler
along with a new ResourceLogger struct in pkg/runtime/log that can
be used to simplify resource-specific log messages.

This new ResourceLogger implements a new AWSLogger interface, which
itself implements a new Tracer interface, which means the ResourceLogger
may be used to provide function or code block tracing capabilities, like
so:

func (r *resourceReconciler) someMethod(
    rlog *ackrtlog.ResourceLogger,
...
) error {
    var err error
    exit := rlog.Trace("someMethod")
    defer exit(err)

    // do some action...
}

This allows for a clean mechanism for "wrapping" the tracing of a
function or a code block.

Example output of these new log messages along with similar debug-level
messages added to the s3-controller's bucket resource manager. These
resource manager-level log messages will need to be added in a separate
patch to the code-generator once this patch merges.

[jaypipes@thelio community]$ k logs -n ack-system ack-s3-controller-55f4487599-f6x6w --follow 
2021-06-18T01:30:35.970Z	INFO	controller-runtime.metrics	metrics server is starting to listen	{"addr": "0.0.0.0:8080"}
2021-06-18T01:30:35.971Z	INFO	setup	initializing service controller	{"aws.service": "s3"}
2021-06-18T01:30:35.973Z	INFO	setup	starting manager	{"aws.service": "s3"}
2021-06-18T01:30:35.973Z	INFO	controller-runtime.manager	starting metrics server	{"path": "/metrics"}
2021-06-18T01:30:35.973Z	INFO	controller-runtime.controller	Starting EventSource	{"controller": "adoptedresource", "source": "kind source: /, Kind="}
2021-06-18T01:30:35.973Z	INFO	controller-runtime.controller	Starting EventSource	{"controller": "bucket", "source": "kind source: /, Kind="}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "kube-node-lease"}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "default"}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "local-path-storage"}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "ack-system"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "kube-node-lease"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "default"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "local-path-storage"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "ack-system"}
2021-06-18T01:30:36.273Z	INFO	controller-runtime.controller	Starting Controller	{"controller": "adoptedresource"}
2021-06-18T01:30:36.273Z	INFO	controller-runtime.controller	Starting workers	{"controller": "adoptedresource", "worker count": 1}
2021-06-18T01:30:36.274Z	INFO	controller-runtime.controller	Starting Controller	{"controller": "bucket"}
2021-06-18T01:30:36.274Z	INFO	controller-runtime.controller	Starting workers	{"controller": "bucket", "worker count": 1}
2021-06-18T01:30:53.524Z	INFO	ackrt	> r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:53.524Z	INFO	ackrt	>> rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:53.524Z	DEBUG	ackrt	>>> rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":null,"conditions":null}}
2021-06-18T01:30:54.431Z	DEBUG	ackrt	<<< rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "error": "resource not found"}
2021-06-18T01:30:54.431Z	INFO	ackrt	<< rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "error": "resource not found"}
2021-06-18T01:30:54.431Z	INFO	ackrt	>> r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.431Z	INFO	ackrt	>>> kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	INFO	ackrt	<<< kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	DEBUG	ackrt	marked resource as managed	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	INFO	ackrt	<< r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	INFO	ackrt	>> rm.Create	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	DEBUG	ackrt	>>> rm.sdkCreate	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":null,"conditions":null}}
2021-06-18T01:30:55.593Z	DEBUG	ackrt	<<< rm.sdkCreate	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:30:55.593Z	INFO	ackrt	<< rm.Create	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.593Z	INFO	ackrt	created new resource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.593Z	INFO	ackrt	>> r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.593Z	INFO	ackrt	>>> kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	INFO	ackrt	<<< kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	DEBUG	ackrt	patched resource status	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "latest": {}}
2021-06-18T01:30:55.596Z	INFO	ackrt	<< r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	INFO	ackrt	< r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}
2021-06-18T01:30:55.596Z	INFO	ackrt	> r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	INFO	ackrt	>> rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	DEBUG	ackrt	>>> rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:30:55.762Z	DEBUG	ackrt	<<< rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:30:55.762Z	INFO	ackrt	<< rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	>> r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	<< r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	>> r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	>>> kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	INFO	ackrt	<<< kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	DEBUG	ackrt	patched resource status	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "latest": {}}
2021-06-18T01:30:55.765Z	INFO	ackrt	<< r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	INFO	ackrt	< r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}
2021-06-18T01:31:14.200Z	INFO	ackrt	> r.cleanup	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.200Z	INFO	ackrt	>> rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.200Z	DEBUG	ackrt	>>> rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:31:14.911Z	DEBUG	ackrt	<<< rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:31:14.911Z	INFO	ackrt	<< rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.911Z	INFO	ackrt	>> rm.Delete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.911Z	DEBUG	ackrt	>>> rm.sdkDelete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:31:15.629Z	DEBUG	ackrt	<<< rm.sdkDelete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.629Z	INFO	ackrt	<< rm.Delete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.629Z	INFO	ackrt	>> r.setResourceUnmanaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.629Z	INFO	ackrt	>>> kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	<<< kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	DEBUG	ackrt	removed resource from management	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	<< r.setResourceUnmanaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	deleted resource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	< r.cleanup	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}
2021-06-18T01:31:15.634Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}

By submitting this pull request, I confirm that my contribution is made under the
terms of the Apache 2.0 license.

Copy link
Contributor

@RedbackThomson RedbackThomson left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see more log values in handleReconcileError - Are you defaulting back to the standard loggers because this is outside the reconciliation loop scope?

Should we also get rid of the DebugResource and InfoResource in resource.go?

Copy link
Member

@a-hilaly a-hilaly left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Very cool stuff, danke herr Jay 👍

@jaypipes
Copy link
Collaborator Author

I see more log values in handleReconcileError - Are you defaulting back to the standard loggers because this is outside the reconciliation loop scope?

sorry, not following you... are you asking for more logging in handleReconcilerError() than what is there?

Should we also get rid of the DebugResource and InfoResource in resource.go?

Not at the moment, since that would break compatibility with controllers using those functions.

@RedbackThomson
Copy link
Contributor

I see more log values in handleReconcileError - Are you defaulting back to the standard loggers because this is outside the reconciliation loop scope?

sorry, not following you... are you asking for more logging in handleReconcilerError() than what is there?

r.log.V(1).Info(

and

r.log.V(1).Info(

@jaypipes
Copy link
Collaborator Author

I see more log values in handleReconcileError - Are you defaulting back to the standard loggers because this is outside the reconciliation loop scope?

sorry, not following you... are you asking for more logging in handleReconcilerError() than what is there?

r.log.V(1).Info(

and

r.log.V(1).Info(

k, understood. will add those. gimme a few miunutes.

@jaypipes jaypipes added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Jun 17, 2021
@jaypipes jaypipes force-pushed the moar-logging branch 2 times, most recently from 48cb85a to 89e58e5 Compare June 18, 2021 01:36
@jaypipes jaypipes removed the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Jun 18, 2021
@jaypipes
Copy link
Collaborator Author

@RedbackThomson @a-hilaly @vijtrip2 OK, guys, I'm happy with this now. Please give another review (I changed quite a bit).

Thanks!
-jay

Copy link
Member

@a-hilaly a-hilaly left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm a huuuuuuge fan of this logger implementation, very very nice!

package types

// AWSLogger is responsible for writing log messages
type AWSLogger interface {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we simply name this interface Logger ?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yeah. will change.

) error {
if res.IsBeingDeleted() {
return r.cleanup(ctx, rm, res)
return r.cleanup(ctx, rlog, rm, res)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not a big deal, but you can also pass the logger via the context. ctx.WithValue("logger", rlog) https://golang.org/pkg/context/#WithValue

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

good idea.

Comment on lines 64 to 66
rl.blockDepth++
depth := strings.Repeat(">", rl.blockDepth)
msg := depth + " " + name
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We can avoid doing unnecessary allocations/ops here

        if rl.log.V(1).Enabled() {
	    rl.blockDepth++
	    depth := strings.Repeat(">", rl.blockDepth)
	    msg := depth + " " + name
            AdaptResource(rl.log, rl.res, additionalValues...).V(1).Info(msg)
        }

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sweet. nice suggestion! 👍

Our debug-level logging wasn't particularly verbose or informative. This
patch adds a number of debug-level log messages into the core reconciler
along with a new `ResourceLogger` struct in `pkg/runtime/log` that can
be used to simplify resource-specific log messages.

This new ResourceLogger implements a new AWSLogger interface, which
itself implements a new Tracer interface, which means the ResourceLogger
may be used to provide function or code block tracing capabilities, like
so:

```go
func (r *resourceReconciler) someMethod(
    ctx context.Context,
...
) error {
    var err error
    rlog := ackrtlog.FromContext(ctx)
    exit := rlog.Trace("someMethod")
    defer exit(err)

    // do some action...
}
```

This allows for a clean mechanism for "wrapping" the tracing of a
function or a code block.

Example output of these new log messages along with similar debug-level
messages added to the s3-controller's bucket resource manager. These
resource manager-level log messages will need to be added in a separate
patch to the code-generator once this patch merges.

```
[jaypipes@thelio community]$ k logs -n ack-system ack-s3-controller-55f4487599-f6x6w --follow
2021-06-18T01:30:35.970Z	INFO	controller-runtime.metrics	metrics server is starting to listen	{"addr": "0.0.0.0:8080"}
2021-06-18T01:30:35.971Z	INFO	setup	initializing service controller	{"aws.service": "s3"}
2021-06-18T01:30:35.973Z	INFO	setup	starting manager	{"aws.service": "s3"}
2021-06-18T01:30:35.973Z	INFO	controller-runtime.manager	starting metrics server	{"path": "/metrics"}
2021-06-18T01:30:35.973Z	INFO	controller-runtime.controller	Starting EventSource	{"controller": "adoptedresource", "source": "kind source: /, Kind="}
2021-06-18T01:30:35.973Z	INFO	controller-runtime.controller	Starting EventSource	{"controller": "bucket", "source": "kind source: /, Kind="}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "kube-node-lease"}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "default"}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "local-path-storage"}
2021-06-18T01:30:36.067Z	DEBUG	ackrt.cache.namespace	created namespace	{"name": "ack-system"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "kube-node-lease"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "default"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "local-path-storage"}
2021-06-18T01:30:36.167Z	DEBUG	adopted-reconciler.cache.namespace	created namespace	{"name": "ack-system"}
2021-06-18T01:30:36.273Z	INFO	controller-runtime.controller	Starting Controller	{"controller": "adoptedresource"}
2021-06-18T01:30:36.273Z	INFO	controller-runtime.controller	Starting workers	{"controller": "adoptedresource", "worker count": 1}
2021-06-18T01:30:36.274Z	INFO	controller-runtime.controller	Starting Controller	{"controller": "bucket"}
2021-06-18T01:30:36.274Z	INFO	controller-runtime.controller	Starting workers	{"controller": "bucket", "worker count": 1}
2021-06-18T01:30:53.524Z	INFO	ackrt	> r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:53.524Z	INFO	ackrt	>> rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:53.524Z	DEBUG	ackrt	>>> rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":null,"conditions":null}}
2021-06-18T01:30:54.431Z	DEBUG	ackrt	<<< rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "error": "resource not found"}
2021-06-18T01:30:54.431Z	INFO	ackrt	<< rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "error": "resource not found"}
2021-06-18T01:30:54.431Z	INFO	ackrt	>> r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.431Z	INFO	ackrt	>>> kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	INFO	ackrt	<<< kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	DEBUG	ackrt	marked resource as managed	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	INFO	ackrt	<< r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	INFO	ackrt	>> rm.Create	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:54.435Z	DEBUG	ackrt	>>> rm.sdkCreate	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":null,"conditions":null}}
2021-06-18T01:30:55.593Z	DEBUG	ackrt	<<< rm.sdkCreate	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:30:55.593Z	INFO	ackrt	<< rm.Create	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.593Z	INFO	ackrt	created new resource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.593Z	INFO	ackrt	>> r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.593Z	INFO	ackrt	>>> kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	INFO	ackrt	<<< kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	DEBUG	ackrt	patched resource status	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "latest": {}}
2021-06-18T01:30:55.596Z	INFO	ackrt	<< r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	INFO	ackrt	< r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}
2021-06-18T01:30:55.596Z	INFO	ackrt	> r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	INFO	ackrt	>> rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.596Z	DEBUG	ackrt	>>> rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:30:55.762Z	DEBUG	ackrt	<<< rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:30:55.762Z	INFO	ackrt	<< rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	>> r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	<< r.setResourceManaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	>> r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.762Z	INFO	ackrt	>>> kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	INFO	ackrt	<<< kc.Patch (status)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	DEBUG	ackrt	patched resource status	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "latest": {}}
2021-06-18T01:30:55.765Z	INFO	ackrt	<< r.patchResource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	INFO	ackrt	< r.Sync	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1, "account": "750630568209", "role": "", "region": "us-west-2", "is_adopted": false, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 1}
2021-06-18T01:30:55.765Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}
2021-06-18T01:31:14.200Z	INFO	ackrt	> r.cleanup	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.200Z	INFO	ackrt	>> rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.200Z	DEBUG	ackrt	>>> rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:31:14.911Z	DEBUG	ackrt	<<< rm.sdkFind	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:31:14.911Z	INFO	ackrt	<< rm.ReadOne	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.911Z	INFO	ackrt	>> rm.Delete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:14.911Z	DEBUG	ackrt	>>> rm.sdkDelete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "spec": {"name":"s3-bucket-cpstsqpcszsgd7"}, "status": {"ackResourceMetadata":{"ownerAccountID":"750630568209"},"conditions":[],"location":"http://s3-bucket-cpstsqpcszsgd7.s3.amazonaws.com/"}}
2021-06-18T01:31:15.629Z	DEBUG	ackrt	<<< rm.sdkDelete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.629Z	INFO	ackrt	<< rm.Delete	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.629Z	INFO	ackrt	>> r.setResourceUnmanaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.629Z	INFO	ackrt	>>> kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	<<< kc.Patch (all)	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	DEBUG	ackrt	removed resource from management	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	<< r.setResourceUnmanaged	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	deleted resource	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	INFO	ackrt	< r.cleanup	{"kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2, "account": "750630568209", "role": "", "region": "us-west-2", "kind": "Bucket", "namespace": "default", "name": "s3-bucket-cpstsqpcszsgd7", "generation": 2}
2021-06-18T01:31:15.634Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}
2021-06-18T01:31:15.634Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "bucket", "request": "default/s3-bucket-cpstsqpcszsgd7"}
```
Comment on lines +22 to +34
const (
// ContextKey is the string key used to store a logger in a Context
ContextKey = "ack.logger"
)

// FromContext returns a `pkg/types.Logger` from a saved key in the request
// context
func FromContext(ctx context.Context) acktypes.Logger {
if v := ctx.Value(ContextKey); v != nil {
return v.(*ResourceLogger)
}
return NoopLogger
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Neat! 👍

@vijtrip2
Copy link
Contributor

Looks very good!

/approve

@ack-bot
Copy link
Collaborator

ack-bot commented Jun 18, 2021

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: A-Hilaly, jaypipes, RedbackThomson, vijtrip2

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:
  • OWNERS [A-Hilaly,RedbackThomson,jaypipes,vijtrip2]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@jaypipes jaypipes merged commit 814ef67 into aws-controllers-k8s:main Jun 20, 2021
r.log, desired,
"is_adopted", isAdopted,
)
rlog.WithValues("is_adopted", isAdopted)
Copy link
Contributor

@surajkota surajkota Jun 22, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why not info or debug so that we know which resource is emitting the log

also, can't see this message in sample log in description

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@surajkota WithValues isn't a log message. What it does is adapt the logger with one or more pairs of key-values that log messages after the call to WithValues will inject in their log lines.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants