mirror of
https://github.com/chillout2k/ExOTA-Milter.git
synced 2025-12-13 10:20:18 +00:00
Merge pull request #32 from chillout2k/devel
Bugfix (#31) + core logging-module + extended debug logging
This commit is contained in:
commit
31a3a43705
@ -2,22 +2,19 @@ import Milter
|
|||||||
import sys
|
import sys
|
||||||
import traceback
|
import traceback
|
||||||
import os
|
import os
|
||||||
import logging
|
|
||||||
import string
|
import string
|
||||||
import random
|
import random
|
||||||
import re
|
import re
|
||||||
import email.utils
|
import email.utils
|
||||||
import authres
|
import authres
|
||||||
import json
|
|
||||||
from policy import (
|
from policy import (
|
||||||
ExOTAPolicyException, ExOTAPolicyNotFoundException,
|
ExOTAPolicyException, ExOTAPolicyNotFoundException,
|
||||||
ExOTAPolicyBackendJSON, ExOTAPolicyBackendLDAP, ExOTAPolicy,
|
ExOTAPolicyBackendJSON, ExOTAPolicyBackendLDAP,
|
||||||
ExOTAPolicyInvalidException, ExOTAPolicyBackendException
|
ExOTAPolicyInvalidException, ExOTAPolicyBackendException
|
||||||
)
|
)
|
||||||
from ldap3 import (
|
from logger import (
|
||||||
Server, Connection, NONE, set_config_parameter
|
init_logger, log_info, log_error, log_debug
|
||||||
)
|
)
|
||||||
from ldap3.core.exceptions import LDAPException
|
|
||||||
|
|
||||||
# Globals with defaults. Can/should be modified by ENV-variables on startup.
|
# Globals with defaults. Can/should be modified by ENV-variables on startup.
|
||||||
# ENV[MILTER_NAME]
|
# ENV[MILTER_NAME]
|
||||||
@ -28,8 +25,6 @@ g_milter_socket = '/socket/' + g_milter_name
|
|||||||
g_milter_reject_message = 'Security policy violation!'
|
g_milter_reject_message = 'Security policy violation!'
|
||||||
# ENV[MILTER_TMPFAIL_MESSAGE]
|
# ENV[MILTER_TMPFAIL_MESSAGE]
|
||||||
g_milter_tmpfail_message = 'Service temporarily not available! Please try again later.'
|
g_milter_tmpfail_message = 'Service temporarily not available! Please try again later.'
|
||||||
# ENV[LOG_LEVEL]
|
|
||||||
g_loglevel = logging.INFO
|
|
||||||
# ENV[MILTER_DKIM_ENABLED]
|
# ENV[MILTER_DKIM_ENABLED]
|
||||||
g_milter_dkim_enabled = False
|
g_milter_dkim_enabled = False
|
||||||
# ENV[MILTER_DKIM_ALIGNMENT_REQUIRED]
|
# ENV[MILTER_DKIM_ALIGNMENT_REQUIRED]
|
||||||
@ -100,7 +95,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
self.mconn_id = g_milter_name + ': ' + ''.join(
|
self.mconn_id = g_milter_name + ': ' + ''.join(
|
||||||
random.choice(string.ascii_lowercase + string.digits) for _ in range(8)
|
random.choice(string.ascii_lowercase + string.digits) for _ in range(8)
|
||||||
)
|
)
|
||||||
logging.debug(self.mconn_id + " reset()")
|
log_debug(self.mconn_id + " reset()")
|
||||||
|
|
||||||
def smfir_reject(self, **kwargs):
|
def smfir_reject(self, **kwargs):
|
||||||
message = g_milter_reject_message
|
message = g_milter_reject_message
|
||||||
@ -110,7 +105,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
message = "queue_id: {0} - {1}".format(kwargs['queue_id'], message)
|
message = "queue_id: {0} - {1}".format(kwargs['queue_id'], message)
|
||||||
if 'reason' in kwargs:
|
if 'reason' in kwargs:
|
||||||
message = "{0} - reason: {1}".format(message, kwargs['reason'])
|
message = "{0} - reason: {1}".format(message, kwargs['reason'])
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
": milter_action=reject message={0}".format(message)
|
": milter_action=reject message={0}".format(message)
|
||||||
)
|
)
|
||||||
self.setreply('550','5.7.1', message)
|
self.setreply('550','5.7.1', message)
|
||||||
@ -124,7 +119,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
message = "queue_id: {0} - {1}".format(kwargs['queue_id'], message)
|
message = "queue_id: {0} - {1}".format(kwargs['queue_id'], message)
|
||||||
if 'reason' in kwargs:
|
if 'reason' in kwargs:
|
||||||
message = "{0} - reason: {1}".format(message, kwargs['reason'])
|
message = "{0} - reason: {1}".format(message, kwargs['reason'])
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
": milter_action=tempfail message={0}".format(message)
|
": milter_action=tempfail message={0}".format(message)
|
||||||
)
|
)
|
||||||
self.setreply('450','4.7.1', message)
|
self.setreply('450','4.7.1', message)
|
||||||
@ -150,24 +145,24 @@ class ExOTAMilter(Milter.Base):
|
|||||||
|
|
||||||
# Mandatory callback
|
# Mandatory callback
|
||||||
def envfrom(self, mailfrom, *str):
|
def envfrom(self, mailfrom, *str):
|
||||||
logging.debug(self.mconn_id + "/FROM 5321.from={0}".format(mailfrom))
|
log_debug(self.mconn_id + "/FROM 5321.from={0}".format(mailfrom))
|
||||||
# Instance member values remain within reused SMTP-connections!
|
# Instance member values remain within reused SMTP-connections!
|
||||||
if self.conn_reused:
|
if self.conn_reused:
|
||||||
# Milter connection reused!
|
# Milter connection reused!
|
||||||
logging.debug(self.mconn_id + "/FROM connection reused!")
|
log_debug(self.mconn_id + "/FROM connection reused!")
|
||||||
self.reset()
|
self.reset()
|
||||||
else:
|
else:
|
||||||
self.conn_reused = True
|
self.conn_reused = True
|
||||||
logging.debug(self.mconn_id + "/FROM client_ip={0}".format(self.client_ip))
|
log_debug(self.mconn_id + "/FROM client_ip={0}".format(self.client_ip))
|
||||||
return self.smfir_continue()
|
return self.smfir_continue()
|
||||||
|
|
||||||
# Mandatory callback
|
# Mandatory callback
|
||||||
def envrcpt(self, to, *str):
|
def envrcpt(self, to, *str):
|
||||||
logging.debug(self.mconn_id + "/RCPT 5321.rcpt={0}".format(to))
|
log_debug(self.mconn_id + "/RCPT 5321.rcpt={0}".format(to))
|
||||||
return self.smfir_continue()
|
return self.smfir_continue()
|
||||||
|
|
||||||
def header(self, name, hval):
|
def header(self, name, hval):
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: Header: {0}, Value: {1}".format(name, hval)
|
"/HDR: Header: {0}, Value: {1}".format(name, hval)
|
||||||
)
|
)
|
||||||
|
|
||||||
@ -177,12 +172,12 @@ class ExOTAMilter(Milter.Base):
|
|||||||
self.hdr_from = hdr_5322_from[1].lower()
|
self.hdr_from = hdr_5322_from[1].lower()
|
||||||
m = re.match(g_re_domain, self.hdr_from)
|
m = re.match(g_re_domain, self.hdr_from)
|
||||||
if m is None:
|
if m is None:
|
||||||
logging.error(self.mconn_id + "/" + str(self.getsymval('i')) + "/HDR " +
|
log_error(self.mconn_id + "/" + str(self.getsymval('i')) + "/HDR " +
|
||||||
"Could not determine domain-part of 5322.from=" + self.hdr_from
|
"Could not determine domain-part of 5322.from=" + self.hdr_from
|
||||||
)
|
)
|
||||||
return self.smfir_reject(queue_id=self.getsymval('i'))
|
return self.smfir_reject(queue_id=self.getsymval('i'))
|
||||||
self.hdr_from_domain = m.group(1)
|
self.hdr_from_domain = m.group(1)
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: 5322.from={0}, 5322.from_domain={1}".format(
|
"/HDR: 5322.from={0}, 5322.from_domain={1}".format(
|
||||||
self.hdr_from, self.hdr_from_domain
|
self.hdr_from, self.hdr_from_domain
|
||||||
)
|
)
|
||||||
@ -194,12 +189,12 @@ class ExOTAMilter(Milter.Base):
|
|||||||
self.hdr_resent_from = hdr_5322_resent_from[1].lower()
|
self.hdr_resent_from = hdr_5322_resent_from[1].lower()
|
||||||
m = re.match(g_re_domain, self.hdr_resent_from)
|
m = re.match(g_re_domain, self.hdr_resent_from)
|
||||||
if m is None:
|
if m is None:
|
||||||
logging.error(self.mconn_id + "/" + str(self.getsymval('i')) + "/HDR " +
|
log_error(self.mconn_id + "/" + str(self.getsymval('i')) + "/HDR " +
|
||||||
"Could not determine domain-part of 5322.resent_from=" + self.hdr_resent_from
|
"Could not determine domain-part of 5322.resent_from=" + self.hdr_resent_from
|
||||||
)
|
)
|
||||||
else:
|
else:
|
||||||
self.hdr_resent_from_domain = m.group(1).lower()
|
self.hdr_resent_from_domain = m.group(1).lower()
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: 5322.resentfrom={0}, 5322.resent_from_domain={1}".format(
|
"/HDR: 5322.resentfrom={0}, 5322.resent_from_domain={1}".format(
|
||||||
self.hdr_resent_from, self.hdr_resent_from_domain
|
self.hdr_resent_from, self.hdr_resent_from_domain
|
||||||
)
|
)
|
||||||
@ -209,7 +204,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
elif(name.lower() == "X-MS-Exchange-CrossTenant-Id".lower()):
|
elif(name.lower() == "X-MS-Exchange-CrossTenant-Id".lower()):
|
||||||
self.hdr_tenant_id_count += 1
|
self.hdr_tenant_id_count += 1
|
||||||
self.hdr_tenant_id = hval.lower()
|
self.hdr_tenant_id = hval.lower()
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: Tenant-ID: {0}".format(self.hdr_tenant_id)
|
"/HDR: Tenant-ID: {0}".format(self.hdr_tenant_id)
|
||||||
)
|
)
|
||||||
|
|
||||||
@ -228,21 +223,21 @@ class ExOTAMilter(Milter.Base):
|
|||||||
self.passed_dkim_results.append({
|
self.passed_dkim_results.append({
|
||||||
"sdid": ar_result.header_d
|
"sdid": ar_result.header_d
|
||||||
})
|
})
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: DKIM passed SDID {0}".format(ar_result.header_d)
|
"/HDR: DKIM passed SDID {0}".format(ar_result.header_d)
|
||||||
)
|
)
|
||||||
self.dkim_valid = True
|
self.dkim_valid = True
|
||||||
else:
|
else:
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: Ignoring authentication results of {0}".format(ar.authserv_id)
|
"/HDR: Ignoring authentication results of {0}".format(ar.authserv_id)
|
||||||
)
|
)
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: AR-parse exception: {0}".format(str(e))
|
"/HDR: AR-parse exception: {0}".format(str(e))
|
||||||
)
|
)
|
||||||
|
|
||||||
elif(name == "X-ExOTA-Authentication-Results"):
|
elif(name == "X-ExOTA-Authentication-Results"):
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/HDR: Found X-ExOTA-Authentication-Results header. Marking for deletion."
|
"/HDR: Found X-ExOTA-Authentication-Results header. Marking for deletion."
|
||||||
)
|
)
|
||||||
self.xar_hdr_count += 1
|
self.xar_hdr_count += 1
|
||||||
@ -257,7 +252,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
if g_milter_x509_enabled:
|
if g_milter_x509_enabled:
|
||||||
for whitelisted_client_ip in g_milter_x509_ip_whitelist:
|
for whitelisted_client_ip in g_milter_x509_ip_whitelist:
|
||||||
if self.client_ip == whitelisted_client_ip:
|
if self.client_ip == whitelisted_client_ip:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i'))
|
log_info(self.mconn_id + "/" + str(self.getsymval('i'))
|
||||||
+ "/EOM: x509 CN check: client-IP '{0}' is whitelisted".format(
|
+ "/EOM: x509 CN check: client-IP '{0}' is whitelisted".format(
|
||||||
whitelisted_client_ip
|
whitelisted_client_ip
|
||||||
)
|
)
|
||||||
@ -266,7 +261,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
if not self.x509_whitelisted:
|
if not self.x509_whitelisted:
|
||||||
cert_subject = self.getsymval('{cert_subject}')
|
cert_subject = self.getsymval('{cert_subject}')
|
||||||
if cert_subject is None:
|
if cert_subject is None:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i'))
|
log_info(self.mconn_id + "/" + str(self.getsymval('i'))
|
||||||
+ "/EOM: No trusted x509 client CN found - action=reject"
|
+ "/EOM: No trusted x509 client CN found - action=reject"
|
||||||
)
|
)
|
||||||
return self.smfir_reject(
|
return self.smfir_reject(
|
||||||
@ -276,11 +271,11 @@ class ExOTAMilter(Milter.Base):
|
|||||||
else:
|
else:
|
||||||
if g_milter_x509_trusted_cn.lower() == cert_subject.lower():
|
if g_milter_x509_trusted_cn.lower() == cert_subject.lower():
|
||||||
self.x509_client_valid = True
|
self.x509_client_valid = True
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Trusted x509 client CN {0}".format(cert_subject)
|
"/EOM: Trusted x509 client CN {0}".format(cert_subject)
|
||||||
)
|
)
|
||||||
else:
|
else:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Untrusted x509 client CN {0} - action=reject".format(cert_subject)
|
"/EOM: Untrusted x509 client CN {0} - action=reject".format(cert_subject)
|
||||||
)
|
)
|
||||||
return self.smfir_reject(
|
return self.smfir_reject(
|
||||||
@ -289,7 +284,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
)
|
)
|
||||||
|
|
||||||
if self.hdr_from is None:
|
if self.hdr_from is None:
|
||||||
logging.error(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_error(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: exception: could not determine 5322.from header - action=reject"
|
"/EOM: exception: could not determine 5322.from header - action=reject"
|
||||||
)
|
)
|
||||||
return self.smfir_reject(
|
return self.smfir_reject(
|
||||||
@ -301,13 +296,13 @@ class ExOTAMilter(Milter.Base):
|
|||||||
policy = None
|
policy = None
|
||||||
try:
|
try:
|
||||||
policy = g_policy_backend.get(self.hdr_from_domain)
|
policy = g_policy_backend.get(self.hdr_from_domain)
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Policy for 5322.from_domain={0} fetched from backend: *{1}*".format(
|
"/EOM: Policy for 5322.from_domain={0} fetched from backend: *{1}*".format(
|
||||||
self.hdr_from_domain, str(policy)
|
self.hdr_from_domain, str(policy)
|
||||||
)
|
)
|
||||||
)
|
)
|
||||||
except ExOTAPolicyBackendException as e:
|
except ExOTAPolicyBackendException as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Policy backend problem: {0}".format(e.message)
|
"/EOM: Policy backend problem: {0}".format(e.message)
|
||||||
)
|
)
|
||||||
return self.smfir_tempfail(
|
return self.smfir_tempfail(
|
||||||
@ -315,7 +310,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
reason = "Policy backend problem"
|
reason = "Policy backend problem"
|
||||||
)
|
)
|
||||||
except ExOTAPolicyInvalidException as e:
|
except ExOTAPolicyInvalidException as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Invalid policy for 5322.from_domain={0}: {1}".format(
|
"/EOM: Invalid policy for 5322.from_domain={0}: {1}".format(
|
||||||
self.hdr_from_domain, e.message
|
self.hdr_from_domain, e.message
|
||||||
)
|
)
|
||||||
@ -327,26 +322,26 @@ class ExOTAMilter(Milter.Base):
|
|||||||
)
|
)
|
||||||
)
|
)
|
||||||
except (ExOTAPolicyException, ExOTAPolicyNotFoundException) as e:
|
except (ExOTAPolicyException, ExOTAPolicyNotFoundException) as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: 5322.from: {0}".format(e.message)
|
"/EOM: 5322.from: {0}".format(e.message)
|
||||||
)
|
)
|
||||||
# Forwarded message? Maybe the Resent-From header domain matches.
|
# Forwarded message? Maybe the Resent-From header domain matches.
|
||||||
if self.hdr_resent_from_domain is not None:
|
if self.hdr_resent_from_domain is not None:
|
||||||
try:
|
try:
|
||||||
policy = g_policy_backend.get(self.hdr_resent_from_domain)
|
policy = g_policy_backend.get(self.hdr_resent_from_domain)
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Policy for 5322.resent_from_domain={0} fetched from backend: *{1}*".format(
|
"/EOM: Policy for 5322.resent_from_domain={0} fetched from backend: *{1}*".format(
|
||||||
self.hdr_resent_from_domain, str(policy)
|
self.hdr_resent_from_domain, str(policy)
|
||||||
)
|
)
|
||||||
)
|
)
|
||||||
self.forwarded = True
|
self.forwarded = True
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Forwarded message -> Policy for 5322.resent_from_domain={0} found.".format(
|
"/EOM: Forwarded message -> Policy for 5322.resent_from_domain={0} found.".format(
|
||||||
self.hdr_resent_from_domain
|
self.hdr_resent_from_domain
|
||||||
)
|
)
|
||||||
)
|
)
|
||||||
except ExOTAPolicyBackendException as e:
|
except ExOTAPolicyBackendException as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Policy backend problem: {0}".format(e.message)
|
"/EOM: Policy backend problem: {0}".format(e.message)
|
||||||
)
|
)
|
||||||
return self.smfir_tempfail(
|
return self.smfir_tempfail(
|
||||||
@ -354,7 +349,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
reason = "Policy backend problem"
|
reason = "Policy backend problem"
|
||||||
)
|
)
|
||||||
except ExOTAPolicyInvalidException as e:
|
except ExOTAPolicyInvalidException as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Invalid policy for 5322.resent_from_domain={0}: {1}".format(
|
"/EOM: Invalid policy for 5322.resent_from_domain={0}: {1}".format(
|
||||||
self.hdr_resent_from_domain, e.message
|
self.hdr_resent_from_domain, e.message
|
||||||
)
|
)
|
||||||
@ -366,7 +361,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
)
|
)
|
||||||
)
|
)
|
||||||
except (ExOTAPolicyException, ExOTAPolicyNotFoundException) as e:
|
except (ExOTAPolicyException, ExOTAPolicyNotFoundException) as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: 5322.resent-from: {0}".format(e.message)
|
"/EOM: 5322.resent-from: {0}".format(e.message)
|
||||||
)
|
)
|
||||||
return self.smfir_reject(
|
return self.smfir_reject(
|
||||||
@ -382,7 +377,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
)
|
)
|
||||||
|
|
||||||
if self.hdr_tenant_id is None:
|
if self.hdr_tenant_id is None:
|
||||||
logging.error(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_error(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: exception: could not determine X-MS-Exchange-CrossTenant-Id - action=reject"
|
"/EOM: exception: could not determine X-MS-Exchange-CrossTenant-Id - action=reject"
|
||||||
)
|
)
|
||||||
return self.smfir_reject(
|
return self.smfir_reject(
|
||||||
@ -390,18 +385,18 @@ class ExOTAMilter(Milter.Base):
|
|||||||
reason = 'Tenant-ID is missing!'
|
reason = 'Tenant-ID is missing!'
|
||||||
)
|
)
|
||||||
if self.hdr_tenant_id_count > 1:
|
if self.hdr_tenant_id_count > 1:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: More than one tenant-IDs for {0} found - action=reject".format(
|
"/EOM: More than one tenant-IDs for {0} found - action=reject".format(
|
||||||
self.hdr_from_domain
|
self.hdr_from_domain
|
||||||
)
|
)
|
||||||
)
|
)
|
||||||
return self.smfir_reject(queue_id=self.getsymval('i'))
|
return self.smfir_reject(queue_id=self.getsymval('i'))
|
||||||
if self.hdr_tenant_id == policy.get_tenant_id():
|
if self.hdr_tenant_id == policy.get_tenant_id():
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: tenant_id={0} status=match".format(self.hdr_tenant_id)
|
"/EOM: tenant_id={0} status=match".format(self.hdr_tenant_id)
|
||||||
)
|
)
|
||||||
else:
|
else:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: tenant_id={0} status=no_match - action=reject".format(
|
"/EOM: tenant_id={0} status=no_match - action=reject".format(
|
||||||
self.hdr_tenant_id
|
self.hdr_tenant_id
|
||||||
)
|
)
|
||||||
@ -412,28 +407,28 @@ class ExOTAMilter(Milter.Base):
|
|||||||
)
|
)
|
||||||
|
|
||||||
if g_milter_dkim_enabled and policy.is_dkim_enabled():
|
if g_milter_dkim_enabled and policy.is_dkim_enabled():
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: 5322.from_domain={0} dkim_auth=enabled".format(self.hdr_from_domain)
|
"/EOM: 5322.from_domain={0} dkim_auth=enabled".format(self.hdr_from_domain)
|
||||||
)
|
)
|
||||||
if self.dkim_valid:
|
if self.dkim_valid:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Valid DKIM signatures found"
|
"/EOM: Valid DKIM signatures found"
|
||||||
)
|
)
|
||||||
for passed_dkim_result in self.passed_dkim_results:
|
for passed_dkim_result in self.passed_dkim_results:
|
||||||
if self.hdr_from_domain == passed_dkim_result['sdid']:
|
if self.hdr_from_domain == passed_dkim_result['sdid']:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Found aligned DKIM signature for SDID: {0}".format(
|
"/EOM: Found aligned DKIM signature for SDID: {0}".format(
|
||||||
passed_dkim_result['sdid']
|
passed_dkim_result['sdid']
|
||||||
)
|
)
|
||||||
)
|
)
|
||||||
self.dkim_aligned = True
|
self.dkim_aligned = True
|
||||||
if not self.dkim_aligned:
|
if not self.dkim_aligned:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: No aligned DKIM signatures found!"
|
"/EOM: No aligned DKIM signatures found!"
|
||||||
)
|
)
|
||||||
if g_milter_dkim_alignment_required:
|
if g_milter_dkim_alignment_required:
|
||||||
if policy.is_dkim_alignment_required() == False:
|
if policy.is_dkim_alignment_required() == False:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Policy overrides DKIM alignment requirement to '{0}'!".format(
|
"/EOM: Policy overrides DKIM alignment requirement to '{0}'!".format(
|
||||||
policy.is_dkim_alignment_required()
|
policy.is_dkim_alignment_required()
|
||||||
)
|
)
|
||||||
@ -444,7 +439,7 @@ class ExOTAMilter(Milter.Base):
|
|||||||
reason = 'DKIM alignment required!'
|
reason = 'DKIM alignment required!'
|
||||||
)
|
)
|
||||||
else:
|
else:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: No valid DKIM authentication result found"
|
"/EOM: No valid DKIM authentication result found"
|
||||||
)
|
)
|
||||||
return self.smfir_reject(
|
return self.smfir_reject(
|
||||||
@ -454,13 +449,13 @@ class ExOTAMilter(Milter.Base):
|
|||||||
|
|
||||||
# Delete all existing X-ExOTA-Authentication-Results headers
|
# Delete all existing X-ExOTA-Authentication-Results headers
|
||||||
for i in range(self.xar_hdr_count, 0, -1):
|
for i in range(self.xar_hdr_count, 0, -1):
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Deleting X-ExOTA-Authentication-Results header"
|
"/EOM: Deleting X-ExOTA-Authentication-Results header"
|
||||||
)
|
)
|
||||||
try:
|
try:
|
||||||
self.chgheader("X-ExOTA-Authentication-Results", i-1, '')
|
self.chgheader("X-ExOTA-Authentication-Results", i-1, '')
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logging.error(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_error(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Deleting X-ExOTA-Authentication-Results failed: {0}".format(str(e))
|
"/EOM: Deleting X-ExOTA-Authentication-Results failed: {0}".format(str(e))
|
||||||
)
|
)
|
||||||
|
|
||||||
@ -474,73 +469,60 @@ class ExOTAMilter(Milter.Base):
|
|||||||
g_milter_authservid, self.hdr_from_domain, policy.is_dkim_enabled(),
|
g_milter_authservid, self.hdr_from_domain, policy.is_dkim_enabled(),
|
||||||
self.dkim_aligned, g_milter_x509_enabled, self.forwarded
|
self.dkim_aligned, g_milter_x509_enabled, self.forwarded
|
||||||
)
|
)
|
||||||
logging.debug(addhdr_value)
|
log_debug(addhdr_value)
|
||||||
self.addheader("X-ExOTA-Authentication-Results", addhdr_value)
|
self.addheader("X-ExOTA-Authentication-Results", addhdr_value)
|
||||||
logging.debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_debug(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: AR-header added"
|
"/EOM: AR-header added"
|
||||||
)
|
)
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: addheader(AR) failed: {0}".format(str(e))
|
"/EOM: addheader(AR) failed: {0}".format(str(e))
|
||||||
)
|
)
|
||||||
|
|
||||||
if g_milter_dkim_enabled:
|
if g_milter_dkim_enabled:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Tenant successfully authorized (dkim_enabled={0} dkim_aligned={1})".format(
|
"/EOM: Tenant successfully authorized (dkim_enabled={0} dkim_aligned={1})".format(
|
||||||
policy.is_dkim_enabled(), self.dkim_aligned
|
policy.is_dkim_enabled(), self.dkim_aligned
|
||||||
)
|
)
|
||||||
)
|
)
|
||||||
else:
|
else:
|
||||||
logging.info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
log_info(self.mconn_id + "/" + str(self.getsymval('i')) +
|
||||||
"/EOM: Tenant successfully authorized"
|
"/EOM: Tenant successfully authorized"
|
||||||
)
|
)
|
||||||
return self.smfir_continue()
|
return self.smfir_continue()
|
||||||
|
|
||||||
def abort(self):
|
def abort(self):
|
||||||
# Client disconnected prematurely
|
# Client disconnected prematurely
|
||||||
logging.debug(self.mconn_id + "/ABORT")
|
log_debug(self.mconn_id + "/ABORT")
|
||||||
return self.smfir_continue()
|
return self.smfir_continue()
|
||||||
|
|
||||||
def close(self):
|
def close(self):
|
||||||
# Always called, even when abort is called.
|
# Always called, even when abort is called.
|
||||||
# Clean up any external resources here.
|
# Clean up any external resources here.
|
||||||
logging.debug(self.mconn_id + "/CLOSE")
|
log_debug(self.mconn_id + "/CLOSE")
|
||||||
return self.smfir_continue()
|
return self.smfir_continue()
|
||||||
|
|
||||||
if __name__ == "__main__":
|
if __name__ == "__main__":
|
||||||
if 'LOG_LEVEL' in os.environ:
|
init_logger()
|
||||||
if re.match(r'^info$', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
|
||||||
g_loglevel = logging.INFO
|
|
||||||
elif re.match(r'^warn|warning$', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
|
||||||
g_loglevel = logging.WARN
|
|
||||||
elif re.match(r'^error$', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
|
||||||
g_loglevel = logging.ERROR
|
|
||||||
elif re.match(r'debug', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
|
||||||
g_loglevel = logging.DEBUG
|
|
||||||
logging.basicConfig(
|
|
||||||
filename=None, # log to stdout
|
|
||||||
format='%(asctime)s: %(levelname)s %(message)s',
|
|
||||||
level=g_loglevel
|
|
||||||
)
|
|
||||||
if 'MILTER_NAME' in os.environ:
|
if 'MILTER_NAME' in os.environ:
|
||||||
g_milter_name = os.environ['MILTER_NAME']
|
g_milter_name = os.environ['MILTER_NAME']
|
||||||
logging.info("ENV[MILTER_NAME]: {0}".format(g_milter_name))
|
log_info("ENV[MILTER_NAME]: {0}".format(g_milter_name))
|
||||||
if 'MILTER_SOCKET' in os.environ:
|
if 'MILTER_SOCKET' in os.environ:
|
||||||
g_milter_socket = os.environ['MILTER_SOCKET']
|
g_milter_socket = os.environ['MILTER_SOCKET']
|
||||||
logging.info("ENV[MILTER_SOCKET]: {0}".format(g_milter_socket))
|
log_info("ENV[MILTER_SOCKET]: {0}".format(g_milter_socket))
|
||||||
if 'MILTER_REJECT_MESSAGE' in os.environ:
|
if 'MILTER_REJECT_MESSAGE' in os.environ:
|
||||||
g_milter_reject_message = os.environ['MILTER_REJECT_MESSAGE']
|
g_milter_reject_message = os.environ['MILTER_REJECT_MESSAGE']
|
||||||
logging.info("ENV[MILTER_REJECT_MESSAGE]: {0}".format(g_milter_reject_message))
|
log_info("ENV[MILTER_REJECT_MESSAGE]: {0}".format(g_milter_reject_message))
|
||||||
if 'MILTER_TMPFAIL_MESSAGE' in os.environ:
|
if 'MILTER_TMPFAIL_MESSAGE' in os.environ:
|
||||||
g_milter_tmpfail_message = os.environ['MILTER_TMPFAIL_MESSAGE']
|
g_milter_tmpfail_message = os.environ['MILTER_TMPFAIL_MESSAGE']
|
||||||
logging.info("ENV[MILTER_TMPFAIL_MESSAGE]: {0}".format(g_milter_tmpfail_message))
|
log_info("ENV[MILTER_TMPFAIL_MESSAGE]: {0}".format(g_milter_tmpfail_message))
|
||||||
if 'MILTER_DKIM_ENABLED' in os.environ:
|
if 'MILTER_DKIM_ENABLED' in os.environ:
|
||||||
g_milter_dkim_enabled = True
|
g_milter_dkim_enabled = True
|
||||||
if 'MILTER_TRUSTED_AUTHSERVID' in os.environ:
|
if 'MILTER_TRUSTED_AUTHSERVID' in os.environ:
|
||||||
g_milter_trusted_authservid = os.environ['MILTER_TRUSTED_AUTHSERVID'].lower()
|
g_milter_trusted_authservid = os.environ['MILTER_TRUSTED_AUTHSERVID'].lower()
|
||||||
logging.info("ENV[MILTER_TRUSTED_AUTHSERVID]: {0}".format(g_milter_trusted_authservid))
|
log_info("ENV[MILTER_TRUSTED_AUTHSERVID]: {0}".format(g_milter_trusted_authservid))
|
||||||
else:
|
else:
|
||||||
logging.error("ENV[MILTER_TRUSTED_AUTHSERVID] is mandatory!")
|
log_error("ENV[MILTER_TRUSTED_AUTHSERVID] is mandatory!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
if 'MILTER_DKIM_ALIGNMENT_REQUIRED' in os.environ:
|
if 'MILTER_DKIM_ALIGNMENT_REQUIRED' in os.environ:
|
||||||
if os.environ['MILTER_DKIM_ALIGNMENT_REQUIRED'] == 'True':
|
if os.environ['MILTER_DKIM_ALIGNMENT_REQUIRED'] == 'True':
|
||||||
@ -548,77 +530,77 @@ if __name__ == "__main__":
|
|||||||
elif os.environ['MILTER_DKIM_ALIGNMENT_REQUIRED'] == 'False':
|
elif os.environ['MILTER_DKIM_ALIGNMENT_REQUIRED'] == 'False':
|
||||||
g_milter_dkim_alignment_required = False
|
g_milter_dkim_alignment_required = False
|
||||||
else:
|
else:
|
||||||
logging.error("ENV[MILTER_DKIM_ALIGNMENT_REQUIRED] must be a boolean type: 'True' or 'False'!")
|
log_error("ENV[MILTER_DKIM_ALIGNMENT_REQUIRED] must be a boolean type: 'True' or 'False'!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
logging.info("ENV[MILTER_DKIM_ALIGNMENT_REQUIRED]: {0}".format(
|
log_info("ENV[MILTER_DKIM_ALIGNMENT_REQUIRED]: {0}".format(
|
||||||
g_milter_dkim_alignment_required
|
g_milter_dkim_alignment_required
|
||||||
))
|
))
|
||||||
logging.info("ENV[MILTER_DKIM_ENABLED]: {0}".format(g_milter_dkim_enabled))
|
log_info("ENV[MILTER_DKIM_ENABLED]: {0}".format(g_milter_dkim_enabled))
|
||||||
if 'MILTER_X509_ENABLED' in os.environ:
|
if 'MILTER_X509_ENABLED' in os.environ:
|
||||||
g_milter_x509_enabled = True
|
g_milter_x509_enabled = True
|
||||||
if 'MILTER_X509_TRUSTED_CN' in os.environ:
|
if 'MILTER_X509_TRUSTED_CN' in os.environ:
|
||||||
g_milter_x509_trusted_cn = os.environ['MILTER_X509_TRUSTED_CN']
|
g_milter_x509_trusted_cn = os.environ['MILTER_X509_TRUSTED_CN']
|
||||||
logging.info("ENV[MILTER_X509_TRUSTED_CN]: {0}".format(g_milter_x509_trusted_cn))
|
log_info("ENV[MILTER_X509_TRUSTED_CN]: {0}".format(g_milter_x509_trusted_cn))
|
||||||
if 'MILTER_X509_IP_WHITELIST' in os.environ:
|
if 'MILTER_X509_IP_WHITELIST' in os.environ:
|
||||||
g_milter_x509_ip_whitelist = "".join(os.environ['MILTER_X509_IP_WHITELIST'].split())
|
g_milter_x509_ip_whitelist = "".join(os.environ['MILTER_X509_IP_WHITELIST'].split())
|
||||||
g_milter_x509_ip_whitelist = g_milter_x509_ip_whitelist.split(',')
|
g_milter_x509_ip_whitelist = g_milter_x509_ip_whitelist.split(',')
|
||||||
logging.info("ENV[MILTER_X509_IP_WHITELIST]: {0}".format(g_milter_x509_ip_whitelist))
|
log_info("ENV[MILTER_X509_IP_WHITELIST]: {0}".format(g_milter_x509_ip_whitelist))
|
||||||
logging.info("ENV[MILTER_X509_ENABLED]: {0}".format(g_milter_x509_enabled))
|
log_info("ENV[MILTER_X509_ENABLED]: {0}".format(g_milter_x509_enabled))
|
||||||
if 'MILTER_ADD_HEADER' in os.environ:
|
if 'MILTER_ADD_HEADER' in os.environ:
|
||||||
g_milter_add_header = True
|
g_milter_add_header = True
|
||||||
if 'MILTER_AUTHSERVID' in os.environ:
|
if 'MILTER_AUTHSERVID' in os.environ:
|
||||||
g_milter_authservid = os.environ['MILTER_AUTHSERVID']
|
g_milter_authservid = os.environ['MILTER_AUTHSERVID']
|
||||||
if not re.match(r'^\S+$', g_milter_authservid):
|
if not re.match(r'^\S+$', g_milter_authservid):
|
||||||
logging.error("ENV[MILTER_AUTHSERVID] is invalid: {0}".format(g_milter_authservid))
|
log_error("ENV[MILTER_AUTHSERVID] is invalid: {0}".format(g_milter_authservid))
|
||||||
logging.info("ENV[MILTER_AUTHSERVID]: {0}".format(g_milter_authservid))
|
log_info("ENV[MILTER_AUTHSERVID]: {0}".format(g_milter_authservid))
|
||||||
else:
|
else:
|
||||||
logging.error("ENV[MILTER_AUTHSERVID] is mandatory!")
|
log_error("ENV[MILTER_AUTHSERVID] is mandatory!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
logging.info("ENV[MILTER_ADD_HEADER]: {0}".format(g_milter_add_header))
|
log_info("ENV[MILTER_ADD_HEADER]: {0}".format(g_milter_add_header))
|
||||||
if 'MILTER_POLICY_SOURCE' in os.environ:
|
if 'MILTER_POLICY_SOURCE' in os.environ:
|
||||||
g_milter_policy_source = os.environ['MILTER_POLICY_SOURCE']
|
g_milter_policy_source = os.environ['MILTER_POLICY_SOURCE']
|
||||||
logging.info("ENV[MILTER_POLICY_SOURCE]: {0}".format(g_milter_policy_source))
|
log_info("ENV[MILTER_POLICY_SOURCE]: {0}".format(g_milter_policy_source))
|
||||||
if g_milter_policy_source == 'file':
|
if g_milter_policy_source == 'file':
|
||||||
if 'MILTER_POLICY_FILE' in os.environ:
|
if 'MILTER_POLICY_FILE' in os.environ:
|
||||||
g_milter_policy_file = os.environ['MILTER_POLICY_FILE']
|
g_milter_policy_file = os.environ['MILTER_POLICY_FILE']
|
||||||
logging.info("ENV[MILTER_POLICY_FILE]: {0}".format(g_milter_policy_file))
|
log_info("ENV[MILTER_POLICY_FILE]: {0}".format(g_milter_policy_file))
|
||||||
try:
|
try:
|
||||||
g_policy_backend = ExOTAPolicyBackendJSON(g_milter_policy_file)
|
g_policy_backend = ExOTAPolicyBackendJSON(g_milter_policy_file)
|
||||||
logging.info("JSON policy backend initialized")
|
log_info("JSON policy backend initialized")
|
||||||
except ExOTAPolicyException as e:
|
except ExOTAPolicyException as e:
|
||||||
logging.error("Policy backend error: {0}".format(e.message))
|
log_error("Policy backend error: {0}".format(e.message))
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
else:
|
else:
|
||||||
logging.error("ENV[MILTER_POLICY_FILE] is mandatory!")
|
log_error("ENV[MILTER_POLICY_FILE] is mandatory!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
elif g_milter_policy_source == 'ldap':
|
elif g_milter_policy_source == 'ldap':
|
||||||
if 'MILTER_LDAP_SERVER_URI' not in os.environ:
|
if 'MILTER_LDAP_SERVER_URI' not in os.environ:
|
||||||
logging.error("ENV[MILTER_LDAP_SERVER_URI] is mandatory!")
|
log_error("ENV[MILTER_LDAP_SERVER_URI] is mandatory!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
g_milter_ldap_server_uri = os.environ['MILTER_LDAP_SERVER_URI']
|
g_milter_ldap_server_uri = os.environ['MILTER_LDAP_SERVER_URI']
|
||||||
if 'MILTER_LDAP_RECEIVE_TIMEOUT' in os.environ:
|
if 'MILTER_LDAP_RECEIVE_TIMEOUT' in os.environ:
|
||||||
try:
|
try:
|
||||||
g_milter_ldap_receive_timeout = int(os.environ['MILTER_LDAP_RECEIVE_TIMEOUT'])
|
g_milter_ldap_receive_timeout = int(os.environ['MILTER_LDAP_RECEIVE_TIMEOUT'])
|
||||||
except ValueError:
|
except ValueError:
|
||||||
logging.error("ENV[MILTER_LDAP_RECEIVE_TIMEOUT] must be an integer!")
|
log_error("ENV[MILTER_LDAP_RECEIVE_TIMEOUT] must be an integer!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
logging.info("ENV[MILTER_LDAP_RECEIVE_TIMEOUT]: {0}".format(
|
log_info("ENV[MILTER_LDAP_RECEIVE_TIMEOUT]: {0}".format(
|
||||||
g_milter_ldap_receive_timeout
|
g_milter_ldap_receive_timeout
|
||||||
))
|
))
|
||||||
if 'MILTER_LDAP_BINDDN' not in os.environ:
|
if 'MILTER_LDAP_BINDDN' not in os.environ:
|
||||||
logging.info("ENV[MILTER_LDAP_BINDDN] not set! Continue...")
|
log_info("ENV[MILTER_LDAP_BINDDN] not set! Continue...")
|
||||||
else:
|
else:
|
||||||
g_milter_ldap_binddn = os.environ['MILTER_LDAP_BINDDN']
|
g_milter_ldap_binddn = os.environ['MILTER_LDAP_BINDDN']
|
||||||
if 'MILTER_LDAP_BINDPW' not in os.environ:
|
if 'MILTER_LDAP_BINDPW' not in os.environ:
|
||||||
logging.info("ENV[MILTER_LDAP_BINDPW] not set! Continue...")
|
log_info("ENV[MILTER_LDAP_BINDPW] not set! Continue...")
|
||||||
else:
|
else:
|
||||||
g_milter_ldap_bindpw = os.environ['MILTER_LDAP_BINDPW']
|
g_milter_ldap_bindpw = os.environ['MILTER_LDAP_BINDPW']
|
||||||
if 'MILTER_LDAP_SEARCH_BASE' not in os.environ:
|
if 'MILTER_LDAP_SEARCH_BASE' not in os.environ:
|
||||||
logging.error("ENV[MILTER_LDAP_SEARCH_BASE] is mandatory!")
|
log_error("ENV[MILTER_LDAP_SEARCH_BASE] is mandatory!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
g_milter_ldap_search_base = os.environ['MILTER_LDAP_SEARCH_BASE']
|
g_milter_ldap_search_base = os.environ['MILTER_LDAP_SEARCH_BASE']
|
||||||
if 'MILTER_LDAP_QUERY' not in os.environ:
|
if 'MILTER_LDAP_QUERY' not in os.environ:
|
||||||
logging.error("ENV[MILTER_LDAP_QUERY] is mandatory!")
|
log_error("ENV[MILTER_LDAP_QUERY] is mandatory!")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
g_milter_ldap_query = os.environ['MILTER_LDAP_QUERY']
|
g_milter_ldap_query = os.environ['MILTER_LDAP_QUERY']
|
||||||
if 'MILTER_LDAP_TENANT_ID_ATTR' in os.environ:
|
if 'MILTER_LDAP_TENANT_ID_ATTR' in os.environ:
|
||||||
@ -628,49 +610,35 @@ if __name__ == "__main__":
|
|||||||
if 'MILTER_LDAP_DKIM_ALIGNMENT_REQUIRED_ATTR' in os.environ:
|
if 'MILTER_LDAP_DKIM_ALIGNMENT_REQUIRED_ATTR' in os.environ:
|
||||||
g_milter_ldap_dkim_alignment_required_attr = os.environ['MILTER_LDAP_DKIM_ALIGNMENT_REQUIRED_ATTR']
|
g_milter_ldap_dkim_alignment_required_attr = os.environ['MILTER_LDAP_DKIM_ALIGNMENT_REQUIRED_ATTR']
|
||||||
try:
|
try:
|
||||||
set_config_parameter("RESTARTABLE_SLEEPTIME", 1)
|
ldap_config = {
|
||||||
set_config_parameter("RESTARTABLE_TRIES", 2)
|
'ldap_server_uri': g_milter_ldap_server_uri,
|
||||||
set_config_parameter('DEFAULT_SERVER_ENCODING', 'utf-8')
|
'ldap_binddn': g_milter_ldap_binddn,
|
||||||
set_config_parameter('DEFAULT_CLIENT_ENCODING', 'utf-8')
|
'ldap_bindpw': g_milter_ldap_bindpw,
|
||||||
server = Server(g_milter_ldap_server_uri, get_info=NONE)
|
'ldap_receive_timeout': g_milter_ldap_receive_timeout,
|
||||||
g_milter_ldap_conn = Connection(server,
|
'ldap_search_base': g_milter_ldap_search_base,
|
||||||
g_milter_ldap_binddn,
|
'ldap_query': g_milter_ldap_query,
|
||||||
g_milter_ldap_bindpw,
|
'ldap_tenant_id_attr': g_milter_ldap_tenant_id_attr,
|
||||||
auto_bind = True,
|
'ldap_dkim_enabled_attr': g_milter_ldap_dkim_enabled_attr,
|
||||||
raise_exceptions = True,
|
'ldap_dkim_alignment_required_attr': g_milter_ldap_dkim_alignment_required_attr
|
||||||
client_strategy = 'RESTARTABLE',
|
}
|
||||||
receive_timeout = g_milter_ldap_receive_timeout
|
g_policy_backend = ExOTAPolicyBackendLDAP(ldap_config)
|
||||||
)
|
log_info("LDAP policy backend initialized")
|
||||||
logging.info("LDAP-Connection established")
|
except ExOTAPolicyException as e:
|
||||||
try:
|
log_error("Policy backend error: {0}".format(e.message))
|
||||||
g_policy_backend = ExOTAPolicyBackendLDAP({
|
|
||||||
'ldap_conn': g_milter_ldap_conn,
|
|
||||||
'ldap_search_base': g_milter_ldap_search_base,
|
|
||||||
'ldap_query': g_milter_ldap_query,
|
|
||||||
'ldap_tenant_id_attr': g_milter_ldap_tenant_id_attr,
|
|
||||||
'ldap_dkim_enabled_attr': g_milter_ldap_dkim_enabled_attr,
|
|
||||||
'ldap_dkim_alignment_required_attr': g_milter_ldap_dkim_alignment_required_attr
|
|
||||||
})
|
|
||||||
logging.info("LDAP policy backend initialized")
|
|
||||||
except ExOTAPolicyException as e:
|
|
||||||
logging.error("Policy backend error: {0}".format(e.message))
|
|
||||||
sys.exit(1)
|
|
||||||
except LDAPException as e:
|
|
||||||
print("LDAP-Exception: {0}".format(e))
|
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
else:
|
else:
|
||||||
logging.debug("Unsupported backend: {0}!".format(g_milter_policy_source))
|
log_debug("Unsupported backend: {0}!".format(g_milter_policy_source))
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
try:
|
try:
|
||||||
timeout = 600
|
timeout = 600
|
||||||
# Register to have the Milter factory create instances of your class:
|
# Register to have the Milter factory create instances of your class:
|
||||||
Milter.factory = ExOTAMilter
|
Milter.factory = ExOTAMilter
|
||||||
Milter.set_flags(Milter.ADDHDRS + Milter.CHGHDRS)
|
Milter.set_flags(Milter.ADDHDRS + Milter.CHGHDRS)
|
||||||
logging.info("Startup " + g_milter_name +
|
log_info("Startup " + g_milter_name +
|
||||||
"@socket: " + g_milter_socket
|
"@socket: " + g_milter_socket
|
||||||
)
|
)
|
||||||
Milter.runmilter(g_milter_name,g_milter_socket,timeout,True)
|
Milter.runmilter(g_milter_name,g_milter_socket,timeout,True)
|
||||||
logging.info("Shutdown " + g_milter_name)
|
log_info("Shutdown " + g_milter_name)
|
||||||
except:
|
except:
|
||||||
logging.error("MAIN-EXCEPTION: " + traceback.format_exc())
|
log_error("MAIN-EXCEPTION: " + traceback.format_exc())
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
35
app/logger.py
Normal file
35
app/logger.py
Normal file
@ -0,0 +1,35 @@
|
|||||||
|
import logging
|
||||||
|
import re
|
||||||
|
import os
|
||||||
|
|
||||||
|
def init_logger():
|
||||||
|
log_level = logging.INFO
|
||||||
|
if 'LOG_LEVEL' in os.environ:
|
||||||
|
if re.match(r'^info$', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
||||||
|
log_level = logging.INFO
|
||||||
|
elif re.match(r'^warn|warning$', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
||||||
|
log_level = logging.WARN
|
||||||
|
elif re.match(r'^error$', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
||||||
|
log_level = logging.ERROR
|
||||||
|
elif re.match(r'debug', os.environ['LOG_LEVEL'], re.IGNORECASE):
|
||||||
|
log_level = logging.DEBUG
|
||||||
|
log_format = '%(asctime)s: %(levelname)s %(message)s '
|
||||||
|
if log_level == logging.DEBUG:
|
||||||
|
# Log thread-ID too. This helps to correlate DEBUG logs,
|
||||||
|
# as Backend-logs do not have a queue_id nor a mconn_id!
|
||||||
|
log_format = '%(asctime)s: %(levelname)s %(thread)d %(message)s '
|
||||||
|
logging.basicConfig(
|
||||||
|
filename = None, # log to stdout
|
||||||
|
format = log_format,
|
||||||
|
level = log_level
|
||||||
|
)
|
||||||
|
logging.info("Logger initialized")
|
||||||
|
|
||||||
|
def log_info(message):
|
||||||
|
logging.info(message)
|
||||||
|
|
||||||
|
def log_error(message):
|
||||||
|
logging.error(message)
|
||||||
|
|
||||||
|
def log_debug(message):
|
||||||
|
logging.debug(message)
|
||||||
@ -3,6 +3,10 @@ import traceback
|
|||||||
import re
|
import re
|
||||||
from uuid import UUID
|
from uuid import UUID
|
||||||
from ldap3.core.exceptions import LDAPException
|
from ldap3.core.exceptions import LDAPException
|
||||||
|
from ldap3 import (
|
||||||
|
Server, Connection, NONE, set_config_parameter
|
||||||
|
)
|
||||||
|
from logger import log_debug
|
||||||
|
|
||||||
class ExOTAPolicyException(Exception):
|
class ExOTAPolicyException(Exception):
|
||||||
def __init__(self, message):
|
def __init__(self, message):
|
||||||
@ -135,30 +139,64 @@ class ExOTAPolicyBackendJSON(ExOTAPolicyBackend):
|
|||||||
class ExOTAPolicyBackendLDAP(ExOTAPolicyBackend):
|
class ExOTAPolicyBackendLDAP(ExOTAPolicyBackend):
|
||||||
type = 'ldap'
|
type = 'ldap'
|
||||||
def __init__(self, ldap_config):
|
def __init__(self, ldap_config):
|
||||||
|
log_debug("init ldap_query: {0}".format(ldap_config['ldap_query']))
|
||||||
try:
|
try:
|
||||||
self.conn = ldap_config['ldap_conn']
|
self.ldap_server_uri = ldap_config['ldap_server_uri']
|
||||||
|
self.ldap_binddn = ldap_config['ldap_binddn']
|
||||||
|
self.ldap_bindpw = ldap_config['ldap_bindpw']
|
||||||
self.search_base = ldap_config['ldap_search_base']
|
self.search_base = ldap_config['ldap_search_base']
|
||||||
self.query = ldap_config['ldap_query']
|
self.ldap_receive_timeout = ldap_config['ldap_receive_timeout']
|
||||||
|
self.query_template = ldap_config['ldap_query']
|
||||||
self.tenant_id_attr = ldap_config['ldap_tenant_id_attr']
|
self.tenant_id_attr = ldap_config['ldap_tenant_id_attr']
|
||||||
self.dkim_enabled_attr = ldap_config['ldap_dkim_enabled_attr']
|
self.dkim_enabled_attr = ldap_config['ldap_dkim_enabled_attr']
|
||||||
self.dkim_alignment_required_attr = ldap_config['ldap_dkim_alignment_required_attr']
|
self.dkim_alignment_required_attr = ldap_config['ldap_dkim_alignment_required_attr']
|
||||||
|
self.connect()
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
raise ExOTAPolicyBackendException(
|
raise ExOTAPolicyBackendException(
|
||||||
"An error occured while initializing LDAP backend: " + traceback.format_exc()
|
"An error occured while initializing LDAP backend: " + traceback.format_exc()
|
||||||
) from e
|
) from e
|
||||||
|
|
||||||
|
def connect(self):
|
||||||
|
try:
|
||||||
|
set_config_parameter("RESTARTABLE_SLEEPTIME", 1)
|
||||||
|
set_config_parameter("RESTARTABLE_TRIES", 2)
|
||||||
|
set_config_parameter('DEFAULT_SERVER_ENCODING', 'utf-8')
|
||||||
|
set_config_parameter('DEFAULT_CLIENT_ENCODING', 'utf-8')
|
||||||
|
self.conn = Connection(
|
||||||
|
Server(self.ldap_server_uri, get_info=NONE),
|
||||||
|
self.ldap_binddn,
|
||||||
|
self.ldap_bindpw,
|
||||||
|
auto_bind = True,
|
||||||
|
raise_exceptions = True,
|
||||||
|
client_strategy = 'RESTARTABLE',
|
||||||
|
receive_timeout = self.ldap_receive_timeout
|
||||||
|
)
|
||||||
|
except LDAPException as e:
|
||||||
|
raise ExOTAPolicyBackendException(
|
||||||
|
"An error occured while connecting to LDAP backend: " + traceback.format_exc()
|
||||||
|
) from e
|
||||||
|
|
||||||
|
def sanitize_connection(self):
|
||||||
|
pass
|
||||||
|
|
||||||
def get(self, from_domain):
|
def get(self, from_domain):
|
||||||
self.query = self.query.replace('%d', from_domain)
|
self.sanitize_connection()
|
||||||
|
log_debug("LDAP FROM_DOMAIN: {0}".format(from_domain))
|
||||||
|
ldap_query = self.query_template
|
||||||
|
ldap_query = ldap_query.replace('%d', from_domain)
|
||||||
|
log_debug("LDAP-QUERY-Template: {0}".format(self.query_template))
|
||||||
|
log_debug("LDAP-QUERY: {0}".format(ldap_query))
|
||||||
try:
|
try:
|
||||||
self.conn.search(
|
self.conn.search(
|
||||||
self.search_base,
|
self.search_base,
|
||||||
self.query,
|
ldap_query,
|
||||||
attributes=[
|
attributes=[
|
||||||
self.tenant_id_attr,
|
self.tenant_id_attr,
|
||||||
self.dkim_enabled_attr,
|
self.dkim_enabled_attr,
|
||||||
self.dkim_alignment_required_attr
|
self.dkim_alignment_required_attr
|
||||||
]
|
]
|
||||||
)
|
)
|
||||||
|
log_debug("LDAP ENTRIES: {0}".format(self.conn.entries))
|
||||||
if len(self.conn.entries) == 1:
|
if len(self.conn.entries) == 1:
|
||||||
entry = self.conn.entries[0]
|
entry = self.conn.entries[0]
|
||||||
policy_dict = {}
|
policy_dict = {}
|
||||||
|
|||||||
64
tests/miltertest_fail.lua
Normal file
64
tests/miltertest_fail.lua
Normal file
@ -0,0 +1,64 @@
|
|||||||
|
-- https://mopano.github.io/sendmail-filter-api/constant-values.html#com.sendmail.milter.MilterConstants
|
||||||
|
-- http://www.opendkim.org/miltertest.8.html
|
||||||
|
|
||||||
|
-- socket must be defined as miltertest global variable (-D)
|
||||||
|
conn = mt.connect(socket)
|
||||||
|
if conn == nil then
|
||||||
|
error "mt.connect() failed"
|
||||||
|
end
|
||||||
|
if mt.conninfo(conn, "localhost", "::1") ~= nil then
|
||||||
|
error "mt.conninfo() failed"
|
||||||
|
end
|
||||||
|
|
||||||
|
mt.set_timeout(60)
|
||||||
|
|
||||||
|
-- 5321.FROM
|
||||||
|
if mt.mailfrom(conn, "envelope.sender@example.org") ~= nil then
|
||||||
|
error "mt.mailfrom() failed"
|
||||||
|
end
|
||||||
|
if mt.getreply(conn) ~= SMFIR_CONTINUE then
|
||||||
|
error "mt.mailfrom() unexpected reply"
|
||||||
|
end
|
||||||
|
|
||||||
|
-- 5321.RCPT+MACROS
|
||||||
|
mt.macro(conn, SMFIC_RCPT, "i", "4CgSNs5Q9sz7FAIL", '{cert_subject}', "mail.protection.outlook.comx")
|
||||||
|
if mt.rcptto(conn, "<envelope.recipient@example.com>") ~= nil then
|
||||||
|
error "mt.rcptto() failed"
|
||||||
|
end
|
||||||
|
if mt.getreply(conn) ~= SMFIR_CONTINUE then
|
||||||
|
error "mt.rcptto() unexpected reply"
|
||||||
|
end
|
||||||
|
|
||||||
|
-- HEADER
|
||||||
|
if mt.header(conn, "fRoM", '"Blah Blubb" <O365ConnectorValidation@chillout2kx.de>') ~= nil then
|
||||||
|
error "mt.header(From) failed"
|
||||||
|
end
|
||||||
|
if mt.header(conn, "x-mS-EXCHANGE-crosstenant-id", "1234abcd-18c5-45e8-88de-123456789abc") ~= nil then
|
||||||
|
error "mt.header(Subject) failed"
|
||||||
|
end
|
||||||
|
if mt.header(conn, "Authentication-Results", "some-validating-host;\n dkim=pass header.d=paypal.de header.s=pp-dkim1 header.b=PmTtUzer;\n dmarc=pass (policy=reject) header.from=paypal.de;\n spf=pass (some-validating-host: domain of service@paypal.de designates 173.0.84.226 as permitted sender) smtp.mailfrom=service@paypal.de") ~= nil then
|
||||||
|
error "mt.header(Subject) failed"
|
||||||
|
end
|
||||||
|
if mt.header(conn, "X-ExOTA-Authentication-Results", "my-auth-serv-id;\n exota=pass") ~= nil then
|
||||||
|
error "mt.header(Subject) failed"
|
||||||
|
end
|
||||||
|
|
||||||
|
-- EOM
|
||||||
|
if mt.eom(conn) ~= nil then
|
||||||
|
error "mt.eom() failed"
|
||||||
|
end
|
||||||
|
mt.echo("EOM: " .. mt.getreply(conn))
|
||||||
|
if mt.getreply(conn) == SMFIR_CONTINUE then
|
||||||
|
mt.echo("EOM-continue")
|
||||||
|
elseif mt.getreply(conn) == SMFIR_REPLYCODE then
|
||||||
|
mt.echo("EOM-reject")
|
||||||
|
end
|
||||||
|
|
||||||
|
if not mt.eom_check(conn, MT_HDRADD, "X-ExOTA-Authentication-Results") then
|
||||||
|
mt.echo("no header added")
|
||||||
|
else
|
||||||
|
mt.echo("X-ExOTA-Authentication-Results header added")
|
||||||
|
end
|
||||||
|
|
||||||
|
-- DISCONNECT
|
||||||
|
mt.disconnect(conn)
|
||||||
Loading…
Reference in New Issue
Block a user