Add accessorID of token when ops are denied by ACL system (#7117)

* agent: add and edit doc comments

* agent: add ACL token accessorID to debugging traces

* agent: polish acl debugging

* agent: minor fix + string fmt over value interp

* agent: undo export & fix logging field names

* agent: remove note and migrate up to code review

* Update agent/consul/acl.go

Co-Authored-By: Matt Keeler <mkeeler@users.noreply.github.com>

* agent: incorporate review feedback

* Update agent/acl.go

Co-Authored-By: R.B. Boyer <public@richardboyer.net>

Co-authored-by: Matt Keeler <mkeeler@users.noreply.github.com>
Co-authored-by: R.B. Boyer <public@richardboyer.net>
This commit is contained in:
Kit Patella 2020-01-27 11:54:32 -08:00 committed by GitHub
parent 01d647f16a
commit 49e9bbbdf9
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 197 additions and 39 deletions

View File

@ -41,6 +41,36 @@ func (a *Agent) resolveTokenAndDefaultMeta(id string, entMeta *structs.Enterpris
return a.delegate.ResolveTokenAndDefaultMeta(id, entMeta, authzContext)
}
// resolveIdentityFromToken is used to resolve an ACLToken's secretID to a structs.ACLIdentity
func (a *Agent) resolveIdentityFromToken(secretID string) (bool, structs.ACLIdentity, error) {
// ACLs are disabled
if !a.delegate.ACLsEnabled() {
return false, nil, nil
}
// Disable ACLs if version 8 enforcement isn't enabled.
if !a.config.ACLEnforceVersion8 {
return false, nil, nil
}
return a.delegate.ResolveIdentityFromToken(secretID)
}
// aclAccessorID is used to convert an ACLToken's secretID to its accessorID for non-
// critical purposes, such as logging. Therefore we interpret all errors as empty-string
// so we can safely log it without handling non-critical errors at the usage site.
func (a *Agent) aclAccessorID(secretID string) string {
_, ident, err := a.resolveIdentityFromToken(secretID)
if err != nil {
a.logger.Printf("[DEBUG] agent.acl: %v", err)
return ""
}
if ident == nil {
return ""
}
return ident.ID()
}
func (a *Agent) initializeACLs() error {
// Build a policy for the agent master token.
// The builtin agent master policy allows reading any node information
@ -250,7 +280,8 @@ func (a *Agent) filterMembers(token string, members *[]serf.Member) error {
if rule.NodeRead(node, &authzContext) == acl.Allow {
continue
}
a.logger.Printf("[DEBUG] agent: dropping node %q from result due to ACLs", node)
accessorID := a.aclAccessorID(token)
a.logger.Printf("[DEBUG] agent: dropping node from result due to ACLs, node=%q accessorID=%q", node, accessorID)
m = append(m[:i], m[i+1:]...)
i--
}
@ -280,7 +311,7 @@ func (a *Agent) filterServicesWithAuthorizer(authz acl.Authorizer, services *map
if authz.ServiceRead(service.Service, &authzContext) == acl.Allow {
continue
}
a.logger.Printf("[DEBUG] agent: dropping service %q from result due to ACLs", id.String())
a.logger.Printf("[DEBUG] agent: dropping service from result due to ACLs, service=%q", id.String())
delete(*services, id)
}
return nil
@ -316,7 +347,7 @@ func (a *Agent) filterChecksWithAuthorizer(authz acl.Authorizer, checks *map[str
continue
}
}
a.logger.Printf("[DEBUG] agent: dropping check %q from result due to ACLs", id.String())
a.logger.Printf("[DEBUG] agent: dropping check from result due to ACLs, check=%q", id.String())
delete(*checks, id)
}
return nil

View File

@ -130,6 +130,19 @@ func (a *TestACLAgent) ResolveTokenAndDefaultMeta(secretID string, entMeta *stru
return authz, err
}
func (a *TestACLAgent) ResolveIdentityFromToken(secretID string) (bool, structs.ACLIdentity, error) {
if a.resolveTokenFn == nil {
panic("This agent is useless without providing a token resolution function")
}
identity, _, err := a.resolveTokenFn(secretID)
if err != nil {
return true, nil, err
}
return true, identity, nil
}
// All of these are stubs to satisfy the interface
func (a *TestACLAgent) Encrypted() bool {
return false

View File

@ -137,6 +137,7 @@ type delegate interface {
RemoveFailedNode(node string, prune bool) error
ResolveToken(secretID string) (acl.Authorizer, error)
ResolveTokenAndDefaultMeta(secretID string, entMeta *structs.EnterpriseMeta, authzContext *acl.AuthorizerContext) (acl.Authorizer, error)
ResolveIdentityFromToken(secretID string) (bool, structs.ACLIdentity, error)
RPC(method string, args interface{}, reply interface{}) error
ACLsEnabled() bool
UseLegacyACLs() bool
@ -152,7 +153,7 @@ type notifier interface {
Notify(string) error
}
// The agent is the long running process that is run on every machine.
// Agent is the long running process that is run on every machine.
// It exposes an RPC interface that is used by the CLI to control the
// agent. The agent runs the query interfaces like HTTP, DNS, and RPC.
// However, it can run in either a client, or server mode. In server
@ -309,6 +310,8 @@ type Agent struct {
persistedTokensLock sync.RWMutex
}
// New verifies the configuration given has a Datacenter and DataDir
// configured, and maps the remaining config fields to fields on the Agent.
func New(c *config.RuntimeConfig, logger *log.Logger) (*Agent, error) {
if c.Datacenter == "" {
return nil, fmt.Errorf("Must configure a Datacenter")
@ -353,6 +356,7 @@ func New(c *config.RuntimeConfig, logger *log.Logger) (*Agent, error) {
return &a, nil
}
// LocalConfig takes a config.RuntimeConfig and maps the fields to a local.Config
func LocalConfig(cfg *config.RuntimeConfig) local.Config {
lc := local.Config{
AdvertiseAddr: cfg.AdvertiseAddrLAN.String(),
@ -369,6 +373,7 @@ func LocalConfig(cfg *config.RuntimeConfig) local.Config {
return lc
}
// Start verifies its configuration and runs an agent's various subprocesses.
func (a *Agent) Start() error {
a.stateLock.Lock()
defer a.stateLock.Unlock()
@ -1877,7 +1882,7 @@ func (a *Agent) ResumeSync() {
}
}
// syncPausedCh returns either a channel or nil. If nil sync is not paused. If
// SyncPausedCh returns either a channel or nil. If nil sync is not paused. If
// non-nil, the channel will be closed when sync resumes.
func (a *Agent) SyncPausedCh() <-chan struct{} {
a.syncMu.Lock()
@ -1921,17 +1926,21 @@ OUTER:
}
for segment, coord := range cs {
agentToken := a.tokens.AgentToken()
req := structs.CoordinateUpdateRequest{
Datacenter: a.config.Datacenter,
Node: a.config.NodeName,
Segment: segment,
Coord: coord,
WriteRequest: structs.WriteRequest{Token: a.tokens.AgentToken()},
WriteRequest: structs.WriteRequest{Token: agentToken},
}
var reply struct{}
// todo(kit) port all of these logger calls to hclog w/ loglevel configuration
// todo(kit) handle acl.ErrNotFound cases here in the future
if err := a.RPC("Coordinate.Update", &req, &reply); err != nil {
if acl.IsErrPermissionDenied(err) {
a.logger.Printf("[WARN] agent: Coordinate update blocked by ACLs")
accessorID := a.aclAccessorID(agentToken)
a.logger.Printf("[DEBUG] agent: Coordinate update blocked by ACLs, accessorID=%v", accessorID)
} else {
a.logger.Printf("[ERR] agent: Coordinate update error: %v", err)
}

View File

@ -178,7 +178,7 @@ type ACLResolverConfig struct {
// - Resolving tokens locally via the ACLResolverDelegate
// - Resolving policies locally via the ACLResolverDelegate
// - Resolving roles locally via the ACLResolverDelegate
// - Resolving legacy tokens remotely via a ACL.GetPolicy RPC
// - Resolving legacy tokens remotely via an ACL.GetPolicy RPC
// - Resolving tokens remotely via an ACL.TokenRead RPC
// - Resolving policies remotely via an ACL.PolicyResolve RPC
// - Resolving roles remotely via an ACL.RoleResolve RPC
@ -437,6 +437,9 @@ func (r *ACLResolver) fetchAndCacheIdentityFromToken(token string, cached *struc
return nil, err
}
// resolveIdentityFromToken takes a token secret as a string and returns an ACLIdentity.
// We read the value from ACLResolver's cache if available, and if the read misses
// we initiate an RPC for the value.
func (r *ACLResolver) resolveIdentityFromToken(token string) (structs.ACLIdentity, error) {
// Attempt to resolve locally first (local results are not cached)
if done, identity, err := r.delegate.ResolveIdentityFromToken(token); done {
@ -765,6 +768,11 @@ func (r *ACLResolver) collectPoliciesForIdentity(identity structs.ACLIdentity, p
var expired []*structs.ACLPolicy
expCacheMap := make(map[string]*structs.PolicyCacheEntry)
var accessorID string
if identity != nil {
accessorID = identity.ID()
}
for _, policyID := range policyIDs {
if done, policy, err := r.delegate.ResolvePolicyFromID(policyID); done {
if err != nil && !acl.IsErrNotFound(err) {
@ -774,7 +782,7 @@ func (r *ACLResolver) collectPoliciesForIdentity(identity structs.ACLIdentity, p
if policy != nil {
policies = append(policies, policy)
} else {
r.logger.Printf("[WARN] acl: policy %q not found for identity %q", policyID, identity.ID())
r.logger.Printf("[WARN] acl: policy not found for identity, policy=%q accessorID=%q", policyID, accessorID)
}
continue
@ -868,7 +876,11 @@ func (r *ACLResolver) collectRolesForIdentity(identity structs.ACLIdentity, role
if role != nil {
roles = append(roles, role)
} else {
r.logger.Printf("[WARN] acl: role %q not found for identity %q", roleID, identity.ID())
var accessorID string
if identity != nil {
accessorID = identity.ID()
}
r.logger.Printf("[WARN] acl: role not found for identity, role=%q accessorID=%q", roleID, accessorID)
}
continue

View File

@ -164,6 +164,7 @@ func (s *Server) ACLsEnabled() bool {
return s.config.ACLsEnabled
}
// ResolveIdentityFromToken retrieves a token's full identity given its secretID.
func (s *Server) ResolveIdentityFromToken(token string) (bool, structs.ACLIdentity, error) {
// only allow remote RPC resolution when token replication is off and
// when not in the ACL datacenter
@ -217,10 +218,12 @@ func (s *Server) ResolveTokenToIdentityAndAuthorizer(token string) (structs.ACLI
return s.acls.ResolveTokenToIdentityAndAuthorizer(token)
}
func (s *Server) ResolveTokenAndDefaultMeta(token string, entMeta *structs.EnterpriseMeta, authzContext *acl.AuthorizerContext) (acl.Authorizer, error) {
// ResolveTokenIdentityAndDefaultMeta retrieves an identity and authorizer for the caller,
// and populates the EnterpriseMeta based on the AuthorizerContext.
func (s *Server) ResolveTokenIdentityAndDefaultMeta(token string, entMeta *structs.EnterpriseMeta, authzContext *acl.AuthorizerContext) (structs.ACLIdentity, acl.Authorizer, error) {
identity, authz, err := s.acls.ResolveTokenToIdentityAndAuthorizer(token)
if err != nil {
return nil, err
return nil, nil, err
}
// Default the EnterpriseMeta based on the Tokens meta or actual defaults
@ -234,6 +237,12 @@ func (s *Server) ResolveTokenAndDefaultMeta(token string, entMeta *structs.Enter
// Use the meta to fill in the ACL authorization context
entMeta.FillAuthzContext(authzContext)
return identity, authz, err
}
// ResolveTokenAndDefaultMeta passes through to ResolveTokenIdentityAndDefaultMeta, eliding the identity from its response.
func (s *Server) ResolveTokenAndDefaultMeta(token string, entMeta *structs.EnterpriseMeta, authzContext *acl.AuthorizerContext) (acl.Authorizer, error) {
_, authz, err := s.ResolveTokenIdentityAndDefaultMeta(token, entMeta, authzContext)
return authz, err
}

View File

@ -38,9 +38,14 @@ func (s *Intention) checkIntentionID(id string) (bool, error) {
// prepareApplyCreate validates that the requester has permissions to create the new intention,
// generates a new uuid for the intention and generally validates that the request is well-formed
func (s *Intention) prepareApplyCreate(authz acl.Authorizer, entMeta *structs.EnterpriseMeta, args *structs.IntentionRequest) error {
func (s *Intention) prepareApplyCreate(ident structs.ACLIdentity, authz acl.Authorizer, entMeta *structs.EnterpriseMeta, args *structs.IntentionRequest) error {
if !args.Intention.CanWrite(authz) {
s.srv.logger.Printf("[WARN] consul.intention: Intention creation denied due to ACLs")
var accessorID string
if ident != nil {
accessorID = ident.ID()
}
// todo(kit) Migrate intention access denial logging over to audit logging when we implement it
s.srv.logger.Printf("[WARN] consul.intention: Intention creation denied due to ACLs, accessorID=%q", accessorID)
return acl.ErrPermissionDenied
}
@ -85,9 +90,14 @@ func (s *Intention) prepareApplyCreate(authz acl.Authorizer, entMeta *structs.En
// prepareApplyUpdate validates that the requester has permissions on both the updated and existing
// intention as well as generally validating that the request is well-formed
func (s *Intention) prepareApplyUpdate(authz acl.Authorizer, entMeta *structs.EnterpriseMeta, args *structs.IntentionRequest) error {
func (s *Intention) prepareApplyUpdate(ident structs.ACLIdentity, authz acl.Authorizer, entMeta *structs.EnterpriseMeta, args *structs.IntentionRequest) error {
if !args.Intention.CanWrite(authz) {
s.srv.logger.Printf("[WARN] consul.intention: Update operation on intention %q denied due to ACLs", args.Intention.ID)
var accessorID string
if ident != nil {
accessorID = ident.ID()
}
// todo(kit) Migrate intention access denial logging over to audit logging when we implement it
s.srv.logger.Printf("[WARN] consul.intention: Update operation on intention denied due to ACLs, intention=%q accessorID=%q", args.Intention.ID, accessorID)
return acl.ErrPermissionDenied
}
@ -103,7 +113,12 @@ func (s *Intention) prepareApplyUpdate(authz acl.Authorizer, entMeta *structs.En
// which must be true to perform any rename. This is the only ACL enforcement
// done for deletions and a secondary enforcement for updates.
if !ixn.CanWrite(authz) {
s.srv.logger.Printf("[WARN] consul.intention: Update operation on intention %q denied due to ACLs", args.Intention.ID)
var accessorID string
if ident != nil {
accessorID = ident.ID()
}
// todo(kit) Migrate intention access denial logging over to audit logging when we implement it
s.srv.logger.Printf("[WARN] consul.intention: Update operation on intention denied due to ACLs, intention=%q accessorID=%q", args.Intention.ID, accessorID)
return acl.ErrPermissionDenied
}
@ -134,7 +149,7 @@ func (s *Intention) prepareApplyUpdate(authz acl.Authorizer, entMeta *structs.En
// prepareApplyDelete ensures that the intention specified by the ID in the request exists
// and that the requester is authorized to delete it
func (s *Intention) prepareApplyDelete(authz acl.Authorizer, entMeta *structs.EnterpriseMeta, args *structs.IntentionRequest) error {
func (s *Intention) prepareApplyDelete(ident structs.ACLIdentity, authz acl.Authorizer, entMeta *structs.EnterpriseMeta, args *structs.IntentionRequest) error {
// If this is not a create, then we have to verify the ID.
state := s.srv.fsm.State()
_, ixn, err := state.IntentionGet(nil, args.Intention.ID)
@ -149,7 +164,12 @@ func (s *Intention) prepareApplyDelete(authz acl.Authorizer, entMeta *structs.En
// which must be true to perform any rename. This is the only ACL enforcement
// done for deletions and a secondary enforcement for updates.
if !ixn.CanWrite(authz) {
s.srv.logger.Printf("[WARN] consul.intention: Deletion operation on intention %q denied due to ACLs", args.Intention.ID)
var accessorID string
if ident != nil {
accessorID = ident.ID()
}
// todo(kit) Migrate intention access denial logging over to audit logging when we implement it
s.srv.logger.Printf("[WARN] consul.intention: Deletion operation on intention denied due to ACLs, intention=%q accessorID=%q", args.Intention.ID, accessorID)
return acl.ErrPermissionDenied
}
@ -179,22 +199,22 @@ func (s *Intention) Apply(
// Get the ACL token for the request for the checks below.
var entMeta structs.EnterpriseMeta
authz, err := s.srv.ResolveTokenAndDefaultMeta(args.Token, &entMeta, nil)
ident, authz, err := s.srv.ResolveTokenIdentityAndDefaultMeta(args.Token, &entMeta, nil)
if err != nil {
return err
}
switch args.Op {
case structs.IntentionOpCreate:
if err := s.prepareApplyCreate(authz, &entMeta, args); err != nil {
if err := s.prepareApplyCreate(ident, authz, &entMeta, args); err != nil {
return err
}
case structs.IntentionOpUpdate:
if err := s.prepareApplyUpdate(authz, &entMeta, args); err != nil {
if err := s.prepareApplyUpdate(ident, authz, &entMeta, args); err != nil {
return err
}
case structs.IntentionOpDelete:
if err := s.prepareApplyDelete(authz, &entMeta, args); err != nil {
if err := s.prepareApplyDelete(ident, authz, &entMeta, args); err != nil {
return err
}
default:
@ -248,7 +268,9 @@ func (s *Intention) Get(
// If ACLs prevented any responses, error
if len(reply.Intentions) == 0 {
s.srv.logger.Printf("[WARN] consul.intention: Request to get intention '%s' denied due to ACLs", args.IntentionID)
accessorID := s.aclAccessorID(args.Token)
// todo(kit) Migrate intention access denial logging over to audit logging when we implement it
s.srv.logger.Printf("[WARN] consul.intention: Request to get intention denied due to ACLs, intention=%s accessorID=%q", args.IntentionID, accessorID)
return acl.ErrPermissionDenied
}
@ -312,7 +334,9 @@ func (s *Intention) Match(
for _, entry := range args.Match.Entries {
entry.FillAuthzContext(&authzContext)
if prefix := entry.Name; prefix != "" && rule.IntentionRead(prefix, &authzContext) != acl.Allow {
s.srv.logger.Printf("[WARN] consul.intention: Operation on intention prefix '%s' denied due to ACLs", prefix)
accessorID := s.aclAccessorID(args.Token)
// todo(kit) Migrate intention access denial logging over to audit logging when we implement it
s.srv.logger.Printf("[WARN] consul.intention: Operation on intention prefix denied due to ACLs, prefix=%s accessorID=%q", prefix, accessorID)
return acl.ErrPermissionDenied
}
}
@ -383,7 +407,9 @@ func (s *Intention) Check(
var authzContext acl.AuthorizerContext
query.FillAuthzContext(&authzContext)
if rule != nil && rule.ServiceRead(prefix, &authzContext) != acl.Allow {
s.srv.logger.Printf("[WARN] consul.intention: test on intention '%s' denied due to ACLs", prefix)
accessorID := s.aclAccessorID(args.Token)
// todo(kit) Migrate intention access denial logging over to audit logging when we implement it
s.srv.logger.Printf("[WARN] consul.intention: test on intention denied due to ACLs, intention=%s accessorID=%q", prefix, accessorID)
return acl.ErrPermissionDenied
}
}
@ -438,3 +464,18 @@ func (s *Intention) Check(
return nil
}
// aclAccessorID is used to convert an ACLToken's secretID to its accessorID for non-
// critical purposes, such as logging. Therefore we interpret all errors as empty-string
// so we can safely log it without handling non-critical errors at the usage site.
func (s *Intention) aclAccessorID(secretID string) string {
_, ident, err := s.srv.ResolveIdentityFromToken(secretID)
if err != nil {
s.srv.logger.Printf("[DEBUG] consul.intention: %v", err)
return ""
}
if ident == nil {
return ""
}
return ident.ID()
}

View File

@ -126,7 +126,8 @@ func (m *Internal) EventFire(args *structs.EventFireRequest,
}
if rule != nil && rule.EventWrite(args.Name, nil) != acl.Allow {
m.srv.logger.Printf("[WARN] consul: user event %q blocked by ACLs", args.Name)
accessorID := m.aclAccessorID(args.Token)
m.srv.logger.Printf("[DEBUG] consul: user event blocked by ACLs, event=%q accessorID=%q", args.Name, accessorID)
return acl.ErrPermissionDenied
}
@ -257,3 +258,18 @@ func (m *Internal) executeKeyringOpMgr(
Error: errStr,
})
}
// aclAccessorID is used to convert an ACLToken's secretID to its accessorID for non-
// critical purposes, such as logging. Therefore we interpret all errors as empty-string
// so we can safely log it without handling non-critical errors at the usage site.
func (m *Internal) aclAccessorID(secretID string) string {
_, ident, err := m.srv.ResolveIdentityFromToken(secretID)
if err != nil {
m.srv.logger.Printf("[DEBUG] consul.internal: %v", err)
return ""
}
if ident == nil {
return ""
}
return ident.ID()
}

View File

@ -121,6 +121,7 @@ func (c *CheckState) CriticalFor() time.Duration {
type rpc interface {
RPC(method string, args interface{}, reply interface{}) error
ResolveIdentityFromToken(secretID string) (bool, structs.ACLIdentity, error)
}
// State is used to represent the node's services,
@ -1079,12 +1080,14 @@ func (l *State) deleteService(key structs.ServiceID) error {
return fmt.Errorf("ServiceID missing")
}
st := l.serviceToken(key)
req := structs.DeregisterRequest{
Datacenter: l.config.Datacenter,
Node: l.config.NodeName,
ServiceID: key.ID,
EnterpriseMeta: key.EnterpriseMeta,
WriteRequest: structs.WriteRequest{Token: l.serviceToken(key)},
WriteRequest: structs.WriteRequest{Token: st},
}
var out struct{}
err := l.Delegate.RPC("Catalog.Deregister", &req, &out)
@ -1104,7 +1107,8 @@ func (l *State) deleteService(key structs.ServiceID) error {
// todo(fs): mark the service to be in sync to prevent excessive retrying before next full sync
// todo(fs): some backoff strategy might be a better solution
l.services[key].InSync = true
l.logger.Printf("[WARN] agent: Service %q deregistration blocked by ACLs", key)
accessorID := l.aclAccessorID(st)
l.logger.Printf("[DEBUG] agent: Service deregistration blocked by ACLs, service=%q accessorID=%v", key.String(), accessorID)
metrics.IncrCounter([]string{"acl", "blocked", "service", "deregistration"}, 1)
return nil
@ -1120,12 +1124,13 @@ func (l *State) deleteCheck(key structs.CheckID) error {
return fmt.Errorf("CheckID missing")
}
ct := l.checkToken(key)
req := structs.DeregisterRequest{
Datacenter: l.config.Datacenter,
Node: l.config.NodeName,
CheckID: key.ID,
EnterpriseMeta: key.EnterpriseMeta,
WriteRequest: structs.WriteRequest{Token: l.checkToken(key)},
WriteRequest: structs.WriteRequest{Token: ct},
}
var out struct{}
err := l.Delegate.RPC("Catalog.Deregister", &req, &out)
@ -1139,7 +1144,8 @@ func (l *State) deleteCheck(key structs.CheckID) error {
// todo(fs): mark the check to be in sync to prevent excessive retrying before next full sync
// todo(fs): some backoff strategy might be a better solution
l.checks[key].InSync = true
l.logger.Printf("[WARN] agent: Check %q deregistration blocked by ACLs", key.String())
accessorID := l.aclAccessorID(ct)
l.logger.Printf("[DEBUG] agent: Check deregistration blocked by ACLs, check=%q accessorID=%q", key.String(), accessorID)
metrics.IncrCounter([]string{"acl", "blocked", "check", "deregistration"}, 1)
return nil
@ -1159,6 +1165,8 @@ func (l *State) pruneCheck(id structs.CheckID) {
// syncService is used to sync a service to the server
func (l *State) syncService(key structs.ServiceID) error {
st := l.serviceToken(key)
// If the service has associated checks that are out of sync,
// piggyback them on the service sync so they are part of the
// same transaction and are registered atomically. We only let
@ -1174,7 +1182,7 @@ func (l *State) syncService(key structs.ServiceID) error {
if !key.Matches(&sid) {
continue
}
if l.serviceToken(key) != l.checkToken(checkKey) {
if st != l.checkToken(checkKey) {
continue
}
checks = append(checks, c.Check)
@ -1189,7 +1197,7 @@ func (l *State) syncService(key structs.ServiceID) error {
NodeMeta: l.metadata,
Service: l.services[key].Service,
EnterpriseMeta: key.EnterpriseMeta,
WriteRequest: structs.WriteRequest{Token: l.serviceToken(key)},
WriteRequest: structs.WriteRequest{Token: st},
}
// Backwards-compatibility for Consul < 0.5
@ -1224,7 +1232,8 @@ func (l *State) syncService(key structs.ServiceID) error {
checkKey.Init(check.CheckID, &check.EnterpriseMeta)
l.checks[checkKey].InSync = true
}
l.logger.Printf("[WARN] agent: Service %q registration blocked by ACLs", key.String())
accessorID := l.aclAccessorID(st)
l.logger.Printf("[DEBUG] agent: Service registration blocked by ACLs, check=%q accessorID=%s", key.String(), accessorID)
metrics.IncrCounter([]string{"acl", "blocked", "service", "registration"}, 1)
return nil
@ -1237,7 +1246,7 @@ func (l *State) syncService(key structs.ServiceID) error {
// syncCheck is used to sync a check to the server
func (l *State) syncCheck(key structs.CheckID) error {
c := l.checks[key]
ct := l.checkToken(key)
req := structs.RegisterRequest{
Datacenter: l.config.Datacenter,
ID: l.config.NodeID,
@ -1247,7 +1256,7 @@ func (l *State) syncCheck(key structs.CheckID) error {
NodeMeta: l.metadata,
Check: c.Check,
EnterpriseMeta: c.Check.EnterpriseMeta,
WriteRequest: structs.WriteRequest{Token: l.checkToken(key)},
WriteRequest: structs.WriteRequest{Token: ct},
}
var serviceKey structs.ServiceID
@ -1274,7 +1283,8 @@ func (l *State) syncCheck(key structs.CheckID) error {
// todo(fs): mark the check to be in sync to prevent excessive retrying before next full sync
// todo(fs): some backoff strategy might be a better solution
l.checks[key].InSync = true
l.logger.Printf("[WARN] agent: Check %q registration blocked by ACLs", key)
accessorID := l.aclAccessorID(ct)
l.logger.Printf("[DEBUG] agent: Check registration blocked by ACLs, check=%q accessorID=%q", key, accessorID)
metrics.IncrCounter([]string{"acl", "blocked", "check", "registration"}, 1)
return nil
@ -1285,6 +1295,7 @@ func (l *State) syncCheck(key structs.CheckID) error {
}
func (l *State) syncNodeInfo() error {
at := l.tokens.AgentToken()
req := structs.RegisterRequest{
Datacenter: l.config.Datacenter,
ID: l.config.NodeID,
@ -1292,7 +1303,7 @@ func (l *State) syncNodeInfo() error {
Address: l.config.AdvertiseAddr,
TaggedAddresses: l.config.TaggedAddresses,
NodeMeta: l.metadata,
WriteRequest: structs.WriteRequest{Token: l.tokens.AgentToken()},
WriteRequest: structs.WriteRequest{Token: at},
}
var out struct{}
err := l.Delegate.RPC("Catalog.Register", &req, &out)
@ -1306,7 +1317,8 @@ func (l *State) syncNodeInfo() error {
// todo(fs): mark the node info to be in sync to prevent excessive retrying before next full sync
// todo(fs): some backoff strategy might be a better solution
l.nodeInfoInSync = true
l.logger.Printf("[WARN] agent: Node info update blocked by ACLs")
accessorID := l.aclAccessorID(at)
l.logger.Printf("[DEBUG] agent: Node info update blocked by ACLs, nodeID=%q accessorID=%q", l.config.NodeID, accessorID)
metrics.IncrCounter([]string{"acl", "blocked", "node", "registration"}, 1)
return nil
@ -1331,3 +1343,18 @@ func (l *State) notifyIfAliased(serviceID structs.ServiceID) {
}
}
}
// aclAccessorID is used to convert an ACLToken's secretID to its accessorID for non-
// critical purposes, such as logging. Therefore we interpret all errors as empty-string
// so we can safely log it without handling non-critical errors at the usage site.
func (l *State) aclAccessorID(secretID string) string {
_, ident, err := l.Delegate.ResolveIdentityFromToken(secretID)
if err != nil {
l.logger.Printf("[DEBUG] agent.local: %v", err)
return ""
}
if ident == nil {
return ""
}
return ident.ID()
}