Repository: qpid-dispatch Updated Branches: refs/heads/master cc4acb147 -> 150a05382
DISPATCH-269: Fix log levels for policy denial. Adjust log messages for coherent narrative by including 'user, host, app'. Repair stats object calling bug. Project: http://git-wip-us.apache.org/repos/asf/qpid-dispatch/repo Commit: http://git-wip-us.apache.org/repos/asf/qpid-dispatch/commit/150a0538 Tree: http://git-wip-us.apache.org/repos/asf/qpid-dispatch/tree/150a0538 Diff: http://git-wip-us.apache.org/repos/asf/qpid-dispatch/diff/150a0538 Branch: refs/heads/master Commit: 150a053823ec4d984965df4817631314d1634c54 Parents: cc4acb1 Author: Chuck Rolke <[email protected]> Authored: Fri Apr 8 18:07:02 2016 -0400 Committer: Chuck Rolke <[email protected]> Committed: Fri Apr 8 18:07:02 2016 -0400 ---------------------------------------------------------------------- .../policy/policy_local.py | 34 +++--- .../policy/policy_util.py | 6 +- src/policy.c | 109 ++++++++++--------- src/policy_internal.h | 3 +- tests/router_policy_test.py | 2 +- 5 files changed, 82 insertions(+), 72 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/qpid-dispatch/blob/150a0538/python/qpid_dispatch_internal/policy/policy_local.py ---------------------------------------------------------------------- diff --git a/python/qpid_dispatch_internal/policy/policy_local.py b/python/qpid_dispatch_internal/policy/policy_local.py index c1bea13..b690c52 100644 --- a/python/qpid_dispatch_internal/policy/policy_local.py +++ b/python/qpid_dispatch_internal/policy/policy_local.py @@ -390,8 +390,8 @@ class AppStats(object): self._manager = manager self.conn_mgr = PolicyAppConnectionMgr( ruleset[PolicyKeys.KW_MAXCONN], - ruleset[PolicyKeys.KW_MAXCONNPERHOST], - ruleset[PolicyKeys.KW_MAXCONNPERUSER]) + ruleset[PolicyKeys.KW_MAXCONNPERUSER], + ruleset[PolicyKeys.KW_MAXCONNPERHOST]) self._cstats = self._manager.get_agent().qd.qd_dispatch_policy_c_counts_alloc() self._manager.get_agent().add_implementation(self, "policyStats") @@ -569,16 +569,16 @@ class PolicyLocal(object): """ try: if not app in self.rulesetdb: - self._manager.log_trace( - "lookup_user failed for user '%s', host '%s', application '%s': " + self._manager.log_info( + "DENY AMQP Open for user '%s', host '%s', application '%s': " "No policy defined for application" % (user, host, app)) return "" ruleset = self.rulesetdb[app] if not app in self.statsdb: msg = ( - "lookup_user failed for user '%s', host '%s', application '%s': " - "Policy is defined but stats are missing" % (user, host, app)) + "DENY AMQP Open for user '%s', host '%s', application '%s': " + "INTERNAL: Policy is defined but stats are missing" % (user, host, app)) raise PolicyError(msg) stats = self.statsdb[app] # User in a group or default? @@ -588,9 +588,9 @@ class PolicyLocal(object): if ruleset[PolicyKeys.KW_CONNECTION_ALLOW_DEFAULT]: usergroup = PolicyKeys.KW_DEFAULT_SETTINGS else: - self._manager.log_trace( - "lookup_user failed for user '%s', host '%s', application '%s': " - "User must be in a user group" % (user, host, app)) + self._manager.log_info( + "DENY AMQP Open for user '%s', host '%s', application '%s': " + "User is not in a user group and default users are denied" % (user, host, app)) stats.count_other_denial() return "" # User in usergroup allowed to connect from host? @@ -611,9 +611,9 @@ class PolicyLocal(object): # User's usergroup has no ingress policy so allow allowed = True if not allowed: - self._manager.log_trace( - "lookup_user failed for user '%s', host '%s', application '%s': " - "User is not allowed to connect from this host" % (user, host, app)) + self._manager.log_info( + "DENY AMQP Open for user '%s', host '%s', application '%s': " + "User is not allowed to connect from this network host" % (user, host, app)) stats.count_other_denial() return "" @@ -622,8 +622,8 @@ class PolicyLocal(object): diags = [] if not stats.can_connect(conn_name, user, host, diags): for diag in diags: - self._manager.log_trace( - "lookup_user failed for user '%s', host '%s', application '%s': " + self._manager.log_info( + "DENY AMQP Open for user '%s', host '%s', application '%s': " "%s" % (user, host, app, diag)) return "" @@ -635,8 +635,8 @@ class PolicyLocal(object): return usergroup except Exception, e: - self._manager.log_error( - "lookup_user failed for user '%s', host '%s', application '%s': " + self._manager.log_info( + "DENY AMQP Open lookup_user failed for user '%s', host '%s', application '%s': " "Internal error: %s" % (user, host, app, e)) # return failure return "" @@ -653,7 +653,7 @@ class PolicyLocal(object): """ try: if not appname in self.rulesetdb: - self._manager.log_trace( + self._manager.log_info( "lookup_settings fail for application '%s', user group '%s': " "No policy defined for this application" % (appname, name)) return False http://git-wip-us.apache.org/repos/asf/qpid-dispatch/blob/150a0538/python/qpid_dispatch_internal/policy/policy_util.py ---------------------------------------------------------------------- diff --git a/python/qpid_dispatch_internal/policy/policy_util.py b/python/qpid_dispatch_internal/policy/policy_util.py index 71a42be..1cb09d3 100644 --- a/python/qpid_dispatch_internal/policy/policy_util.py +++ b/python/qpid_dispatch_internal/policy/policy_util.py @@ -309,11 +309,11 @@ class PolicyAppConnectionMgr(object): return True else: if not allowbytotal: - diags.append("Connection denied by total connection limit") + diags.append("Connection denied by application connection limit") if not allowbyuser: - diags.append("Connection denied by per user limit") + diags.append("Connection denied by application per user limit") if not allowbyhost: - diags.append("Connection denied by per host limit") + diags.append("Connection denied by application per host limit") self.connections_denied += 1 return False http://git-wip-us.apache.org/repos/asf/qpid-dispatch/blob/150a0538/src/policy.c ---------------------------------------------------------------------- diff --git a/src/policy.c b/src/policy.c index bb35cf2..a5e2f57 100644 --- a/src/policy.c +++ b/src/policy.c @@ -202,12 +202,12 @@ bool qd_policy_socket_accept(void *context, const char *hostname) if (n_connections < policy->max_connection_limit) { // connection counted and allowed n_connections += 1; - qd_log(policy->log_source, QD_LOG_DEBUG, "Connection '%s' allowed. N= %d", hostname, n_connections); + qd_log(policy->log_source, QD_LOG_TRACE, "ALLOW Connection '%s' based on global connection count. N= %d", hostname, n_connections); } else { // connection denied result = false; n_denied += 1; - qd_log(policy->log_source, QD_LOG_DEBUG, "Connection '%s' denied, N=%d", hostname, n_connections); + qd_log(policy->log_source, QD_LOG_INFO, "DENY Connection '%s' based on global connection count. N= %d", hostname, n_connections); } } n_processed += 1; @@ -250,7 +250,7 @@ void qd_policy_socket_close(void *context, const qd_connection_t *conn) } if (policy->max_connection_limit > 0) { const char *hostname = qdpn_connector_name(conn->pn_cxtr); - qd_log(policy->log_source, QD_LOG_DEBUG, "Connection '%s' closed with resources n_sessions=%d, n_senders=%d, n_receivers=%d. Total connections=%d.", + qd_log(policy->log_source, QD_LOG_DEBUG, "Connection '%s' closed with resources n_sessions=%d, n_senders=%d, n_receivers=%d. N= %d.", hostname, conn->n_sessions, conn->n_senders, conn->n_receivers, n_connections); } } @@ -368,10 +368,14 @@ bool qd_policy_open_lookup_user( Py_XDECREF(module); qd_python_unlock(lock_state); - qd_log(policy->log_source, - QD_LOG_DEBUG, - "Policy AMQP Open lookup_user: %s, hostip: %s, app: %s, connection: %s. Usergroup: '%s'%s", + if (name_buf[0]) { + qd_log(policy->log_source, + QD_LOG_TRACE, + "ALLOW AMQP Open lookup_user: %s, hostip: %s, app: %s, connection: %s. Usergroup: '%s'%s", username, hostip, appname, conn_name, name_buf, (res ? "" : " Internal error.")); + } else { + // Denials are logged in python code + } return res; } @@ -385,6 +389,7 @@ void qd_policy_private_deny_amqp_connection(pn_connection_t *conn, const char *c (void) pn_condition_set_name( cond, cond_name); (void) pn_condition_set_description(cond, cond_descr); pn_connection_close(conn); + // Connection denial counts are counted and logged by python code. } @@ -396,17 +401,6 @@ void qd_policy_deny_amqp_session(pn_session_t *ssn, qd_connection_t *qd_conn) (void) pn_condition_set_name( cond, RESOURCE_LIMIT_EXCEEDED); (void) pn_condition_set_description(cond, SESSION_DISALLOWED); pn_session_close(ssn); - - pn_connection_t *conn = qd_connection_pn(qd_conn); - qd_dispatch_t *qd = qd_conn->server->qd; - qd_policy_t *policy = qd->policy; - const char *hostip = qdpn_connector_hostip(qd_conn->pn_cxtr); - const char *app = pn_connection_remote_hostname(conn); - qd_log(policy->log_source, - QD_LOG_DEBUG, - "Policy AMQP Begin Session denied due to session limit. user: %s, hostip: %s, app: %s", - qd_conn->user_id, hostip, app); - qd_conn->policy_settings->denialCounts->sessionDenied++; } @@ -415,16 +409,32 @@ void qd_policy_deny_amqp_session(pn_session_t *ssn, qd_connection_t *qd_conn) // bool qd_policy_approve_amqp_session(pn_session_t *ssn, qd_connection_t *qd_conn) { + bool result = true; if (qd_conn->policy_settings) { if (qd_conn->policy_settings->maxSessions) { if (qd_conn->n_sessions == qd_conn->policy_settings->maxSessions) { qd_policy_deny_amqp_session(ssn, qd_conn); - return false; + result = false; } } } - // Approved - return true; + pn_connection_t *conn = qd_connection_pn(qd_conn); + qd_dispatch_t *qd = qd_conn->server->qd; + qd_policy_t *policy = qd->policy; + const char *hostip = qdpn_connector_hostip(qd_conn->pn_cxtr); + const char *app = pn_connection_remote_hostname(conn); + if (result) { + qd_log(policy->log_source, + QD_LOG_TRACE, + "ALLOW AMQP Begin Session. user: %s, hostip: %s, app: %s", + qd_conn->user_id, hostip, app); + } else { + qd_log(policy->log_source, + QD_LOG_INFO, + "DENY AMQP Begin Session due to session limit. user: %s, hostip: %s, app: %s", + qd_conn->user_id, hostip, app); + } + return result; } @@ -441,22 +451,12 @@ void qd_policy_apply_session_settings(pn_session_t *ssn, qd_connection_t *qd_con // // -void _qd_policy_deny_amqp_link(pn_link_t *link, qd_connection_t *qd_conn, char * s_or_r) +void _qd_policy_deny_amqp_link(pn_link_t *link, qd_connection_t *qd_conn) { pn_condition_t * cond = pn_link_condition(link); (void) pn_condition_set_name( cond, RESOURCE_LIMIT_EXCEEDED); (void) pn_condition_set_description(cond, LINK_DISALLOWED); pn_link_close(link); - - pn_connection_t *conn = qd_connection_pn(qd_conn); - qd_dispatch_t *qd = qd_conn->server->qd; - qd_policy_t *policy = qd->policy; - const char *hostip = qdpn_connector_hostip(qd_conn->pn_cxtr); - const char *app = pn_connection_remote_hostname(conn); - qd_log(policy->log_source, - QD_LOG_DEBUG, - "Policy AMQP Attach Link denied due to %s limit. user: %s, hostip: %s, app: %s", - s_or_r, qd_conn->user_id, hostip, app); } @@ -464,7 +464,7 @@ void _qd_policy_deny_amqp_link(pn_link_t *link, qd_connection_t *qd_conn, char * // void _qd_policy_deny_amqp_sender_link(pn_link_t *pn_link, qd_connection_t *qd_conn) { - _qd_policy_deny_amqp_link(pn_link, qd_conn, "sender"); + _qd_policy_deny_amqp_link(pn_link, qd_conn); qd_conn->policy_settings->denialCounts->senderDenied++; } @@ -473,7 +473,7 @@ void _qd_policy_deny_amqp_sender_link(pn_link_t *pn_link, qd_connection_t *qd_co // void _qd_policy_deny_amqp_receiver_link(pn_link_t *pn_link, qd_connection_t *qd_conn) { - _qd_policy_deny_amqp_link(pn_link, qd_conn, "receiver"); + _qd_policy_deny_amqp_link(pn_link, qd_conn); qd_conn->policy_settings->denialCounts->receiverDenied++; } @@ -486,7 +486,7 @@ char * _qd_policy_link_user_name_subst(const char *uname, const char *proposed, { if (strlen(uname) == 0) return NULL; - + const char *duser = "${user}"; char *retptr = obuf; const char *wiptr = proposed; @@ -590,9 +590,15 @@ bool _qd_policy_approve_link_name(const char *username, const char *allowed, con // bool qd_policy_approve_amqp_sender_link(pn_link_t *pn_link, qd_connection_t *qd_conn) { + const char *hostip = qdpn_connector_hostip(qd_conn->pn_cxtr); + const char *app = pn_connection_remote_hostname(qd_connection_pn(qd_conn)); + if (qd_conn->policy_settings->maxSenders) { if (qd_conn->n_senders == qd_conn->policy_settings->maxSenders) { // Max sender limit specified and violated. + qd_log(qd_conn->server->qd->policy->log_source, QD_LOG_INFO, + "DENY AMQP Attach sender for user '%s', host '%s', app '%s' based on maxSenders limit", + qd_conn->user_id, hostip, app); _qd_policy_deny_amqp_sender_link(pn_link, qd_conn); return false; } else { @@ -608,9 +614,9 @@ bool qd_policy_approve_amqp_sender_link(pn_link_t *pn_link, qd_connection_t *qd_ // a target is specified lookup = _qd_policy_approve_link_name(qd_conn->user_id, qd_conn->policy_settings->targets, target); - qd_log(qd_conn->server->qd->policy->log_source, QD_LOG_TRACE, - "Approve sender link '%s' for user '%s': %s", - target, qd_conn->user_id, (lookup ? "ALLOW" : "DENY")); + qd_log(qd_conn->server->qd->policy->log_source, (lookup ? QD_LOG_TRACE : QD_LOG_INFO), + "%s AMQP Attach sender link '%s' for user '%s', host '%s', app '%s' based on link target name", + (lookup ? "ALLOW" : "DENY"), target, qd_conn->user_id, hostip, app); if (!lookup) { _qd_policy_deny_amqp_receiver_link(pn_link, qd_conn); @@ -620,9 +626,9 @@ bool qd_policy_approve_amqp_sender_link(pn_link_t *pn_link, qd_connection_t *qd_ // A sender with no remote target. // This happens all the time with anonymous relay lookup = qd_conn->policy_settings->allowAnonymousSender; - qd_log(qd_conn->server->qd->policy->log_source, QD_LOG_TRACE, - "Approve anonymous relay sender link for user '%s': %s", - qd_conn->user_id, (lookup ? "ALLOW" : "DENY")); + qd_log(qd_conn->server->qd->policy->log_source, (lookup ? QD_LOG_TRACE : QD_LOG_INFO), + "%s AMQP Attach anonymous sender for user '%s', host '%s', app '%s'", + (lookup ? "ALLOW" : "DENY"), qd_conn->user_id, hostip, app); if (!lookup) { _qd_policy_deny_amqp_receiver_link(pn_link, qd_conn); return false; @@ -635,9 +641,15 @@ bool qd_policy_approve_amqp_sender_link(pn_link_t *pn_link, qd_connection_t *qd_ bool qd_policy_approve_amqp_receiver_link(pn_link_t *pn_link, qd_connection_t *qd_conn) { + const char *hostip = qdpn_connector_hostip(qd_conn->pn_cxtr); + const char *app = pn_connection_remote_hostname(qd_connection_pn(qd_conn)); + if (qd_conn->policy_settings->maxReceivers) { if (qd_conn->n_receivers == qd_conn->policy_settings->maxReceivers) { // Max sender limit specified and violated. + qd_log(qd_conn->server->qd->policy->log_source, QD_LOG_INFO, + "DENY AMQP Attach receiver for user '%s', host '%s', app '%s' based on maxReceivers limit", + qd_conn->user_id, hostip, app); _qd_policy_deny_amqp_receiver_link(pn_link, qd_conn); return false; } else { @@ -650,9 +662,9 @@ bool qd_policy_approve_amqp_receiver_link(pn_link_t *pn_link, qd_connection_t *q bool dynamic_src = pn_terminus_is_dynamic(pn_link_remote_source(pn_link)); if (dynamic_src) { bool lookup = qd_conn->policy_settings->allowDynamicSrc; - qd_log(qd_conn->server->qd->policy->log_source, QD_LOG_TRACE, - "Approve dynamic source for user '%s': %s", - qd_conn->user_id, (lookup ? "ALLOW" : "DENY")); + qd_log(qd_conn->server->qd->policy->log_source, (lookup ? QD_LOG_TRACE : QD_LOG_INFO), + "%s AMQP Attach receiver dynamic source for user '%s', host '%s', app '%s',", + (lookup ? "ALLOW" : "DENY"), qd_conn->user_id, hostip, app); // Dynamic source policy rendered the decision if (!lookup) { _qd_policy_deny_amqp_receiver_link(pn_link, qd_conn); @@ -664,9 +676,9 @@ bool qd_policy_approve_amqp_receiver_link(pn_link_t *pn_link, qd_connection_t *q // a source is specified bool lookup = _qd_policy_approve_link_name(qd_conn->user_id, qd_conn->policy_settings->sources, source); - qd_log(qd_conn->server->qd->policy->log_source, QD_LOG_TRACE, - "Approve receiver link '%s' for user '%s': %s", - source, qd_conn->user_id, (lookup ? "ALLOW" : "DENY")); + qd_log(qd_conn->server->qd->policy->log_source, (lookup ? QD_LOG_TRACE : QD_LOG_INFO), + "%s AMQP Attach receiver link '%s' for user '%s', host '%s', app '%s' based on link source name", + (lookup ? "ALLOW" : "DENY"), source, qd_conn->user_id, hostip, app); if (!lookup) { _qd_policy_deny_amqp_receiver_link(pn_link, qd_conn); @@ -675,9 +687,8 @@ bool qd_policy_approve_amqp_receiver_link(pn_link_t *pn_link, qd_connection_t *q } else { // A receiver with no remote source. qd_log(qd_conn->server->qd->policy->log_source, QD_LOG_TRACE, - "Approve receiver link '' for user '%s': DENY", - qd_conn->user_id); - + "DENY AMQP Attach receiver link '' for user '%s', host '%s', app '%s'", + qd_conn->user_id, hostip, app); _qd_policy_deny_amqp_receiver_link(pn_link, qd_conn); return false; } http://git-wip-us.apache.org/repos/asf/qpid-dispatch/blob/150a0538/src/policy_internal.h ---------------------------------------------------------------------- diff --git a/src/policy_internal.h b/src/policy_internal.h index 9e865e6..47572f7 100644 --- a/src/policy_internal.h +++ b/src/policy_internal.h @@ -46,9 +46,8 @@ void qd_policy_deny_amqp_session(pn_session_t *ssn, qd_connection_t *qd_conn); * The link is closed and the denial is logged but not counted. * @param[in] link proton link being closed * @param[in] qd_conn the qd conection - * @param[in] s_or_r 'sender' or 'receiver' for logging */ -void _qd_policy_deny_amqp_link(pn_link_t *link, qd_connection_t *qd_conn, char * s_or_r); +void _qd_policy_deny_amqp_link(pn_link_t *link, qd_connection_t *qd_conn); /** Internal function to deny a sender amqp link http://git-wip-us.apache.org/repos/asf/qpid-dispatch/blob/150a0538/tests/router_policy_test.py ---------------------------------------------------------------------- diff --git a/tests/router_policy_test.py b/tests/router_policy_test.py index bbffd98..9b37567 100644 --- a/tests/router_policy_test.py +++ b/tests/router_policy_test.py @@ -198,7 +198,7 @@ class PolicyAppConnectionMgrTests(TestCase): self.assertTrue(stats.can_connect('10.10.10.10:10000', 'chuck', '10.10.10.10', diags)) self.assertFalse(stats.can_connect('10.10.10.10:10001', 'chuck', '10.10.10.10', diags)) self.assertTrue(len(diags) == 1) - self.assertTrue('by total' in diags[0]) + self.assertTrue('application connection limit' in diags[0]) def test_policy_app_conn_mgr_fail_by_user(self): stats = PolicyAppConnectionMgr(3, 1, 2) --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
