Add telemetry instrumentation for delegated identity API and add latency telemetry util

[chiragk25]

Add telemetry instrumentation for delegated identity API and add latency telemetry util

Pull Request check list

• Commit conforms to CONTRIBUTING.md?
• Proper tests/regressions included?
• Documentation updated?

Description of change

This change adds telemetry instrumentation for delegated identity API. It also adds a new telemetry type Latency which is a generic version of a CallCounter acting as a wrapper for temetry.MeasureSinceWithLabels. It is used in delegated identity SubscribeToX509SVIDs streaming API to measure the time it takes since stream start until the first X.509 SVID update is received.

This change also adds some Info/Debug level logs in the API for observability.

Which issue this PR fixes

fixes #4344

[rturner3]

The linter is complaining about a couple things in this PR, could you address them? You can run the linter with make lint (requires Docker to be running locally).

pkg/common/telemetry/latency.go:12: File is not `goimports`-ed (goimports)
//		func Foo() {
//		    latency := StartLatencyMetric(metrics, "foo")
//		 	call.AddLabel("food", "burgers")
//  		// do something
//	     	latency.Measure() // measure time elapsed between StartLatencyMetric() and Measure()
//			// do other things
//		}
pkg/agent/api/delegatedidentity/v1/service_test.go:8: File is not `goimports`-ed (goimports)
	"github.com/spiffe/spire/test/fakes/fakemetrics"
pkg/common/telemetry/latency.go:38:2: field `done` is unused (unused)
	done    bool
	^

[chiragk25]

Metrics from test run -

$ curl http://localhost:9988 | grep delegated
# HELP spire_agent_delegated_identity_api_connection spire_agent_delegated_identity_api_connection
# TYPE spire_agent_delegated_identity_api_connection counter
:spire_agent_delegated_identity_api_connection{host="chirag-kapadia-F9F3DQ20WF"} 8
-# HELP spire_agent_delegated_identity_api_connections spire_agent_delegated_identity_api_connections
# TYPE spire_agent_delegated_identity_api_connections gauge
-spire_agent_delegated_identity_api_connections{host="chirag-kapadia-F9F3DQ20WF"} 0
 # HELP spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time
# TYPE spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time summary
-spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time{host="chirag-kapadia-F9F3DQ20WF",quantile="0.5"} 252.00045776367188
-spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time{host="chirag-kapadia-F9F3DQ20WF",quantile="0.9"} 252.00045776367188
:--:-spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time{host="chirag-kapadia-F9F3DQ20WF",quantile="0.99"} 252.00045776367188
- spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time_sum{host="chirag-kapadia-F9F3DQ20WF"} 2017.0548248291016
35spire_agent_delegated_identity_api_subscribe_x509_svids_first_x509_svid_update_elapsed_time_count{host="chirag-kapadia-F9F3DQ20WF"} 8
77k
# HELP spire_agent_rpc_delegated_identity_subscribe_to_x509_svids spire_agent_rpc_delegated_identity_subscribe_to_x509_svids
# TYPE spire_agent_rpc_delegated_identity_subscribe_to_x509_svids counter
spire_agent_rpc_delegated_identity_subscribe_to_x509_svids{host="chirag-kapadia-F9F3DQ20WF",status="OK"} 8
# HELP spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time
# TYPE spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time summary
spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time{host="chirag-kapadia-F9F3DQ20WF",status="OK",quantile="0.5"} 5431.31494140625
spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time{host="chirag-kapadia-F9F3DQ20WF",status="OK",quantile="0.9"} 5431.31494140625
spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time{host="chirag-kapadia-F9F3DQ20WF",status="OK",quantile="0.99"} 5431.31494140625
spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time_sum{host="chirag-kapadia-F9F3DQ20WF",status="OK"} 45253.39454650879
spire_agent_rpc_delegated_identity_subscribe_to_x509_svids_elapsed_time_count{host="chirag-kapadia-F9F3DQ20WF",status="OK"} 8

Relevant log messages:

DEBU[0003] PID attested to have selectors                pid=76433 selectors="[type:\"unix\" value:\"uid:501\" type:\"unix\" value:\"user:chirag.kapadia\" type:\"unix\" value:\"gid:20\" type:\"unix\" value:\"group:staff\"]" subsystem_name=workload_attestor
DEBU[0003] Caller authorized as delegate                 delegate_id="spiffe://example.org/authorized_client1" delegate_selectors="[type:\"unix\" value:\"uid:501\" type:\"unix\" value:\"user:chirag.kapadia\" type:\"unix\" value:\"gid:20\" type:\"unix\" value:\"group:staff\"]" method=SubscribeToX509SVIDs pid=76433 service=DelegatedIdentity
INFO[0003] Subscribing to cache changes                  delegate_selectors="[type:\"unix\" value:\"uid:501\" type:\"unix\" value:\"user:chirag.kapadia\" type:\"unix\" value:\"gid:20\" type:\"unix\" value:\"group:staff\"]" method=SubscribeToX509SVIDs pid=76433 request_selectors="[type:\"unix\" value:\"uid:501\"]" service=DelegatedIdentity
DEBU[0003] Caller authorized as delegate                 delegate_id="spiffe://example.org/authorized_client1" delegate_selectors="[type:\"unix\" value:\"uid:501\" type:\"unix\" value:\"user:chirag.kapadia\" type:\"unix\" value:\"gid:20\" type:\"unix\" value:\"group:staff\"]" method=SubscribeToX509SVIDs pid=76433 service=DelegatedIdentity
DEBU[0003] Fetched X.509 SVID for delegated identity     count=1 method=SubscribeToX509SVIDs pid=76433 service=DelegatedIdentity spiffe_id="trust_domain:\"example.org\" path:\"/authorized_client1\"" ttl=3595.917394