python 具有基本日志记录的 aiosmtpd 服务器

python aiosmtpd server with basic logging

我已经知道 aiosmtpd 记录到系统日志。我使用的是 Red Hat Linux 发行版,但在消息或邮件日志文件中找不到与我的 SMTP 服务器相关的任何内容。我正在尝试调试无法使用基本身份验证连接到我的 SMTP 服务器的设备问题,因为我找不到该设备被我的服务器拒绝的任何原因。到目前为止,我能够调试的唯一方法是使用 EHLO 和 MAIL 处理程序,并在达到该连接阶段时打印一条消息。理想情况下,我希望尽可能多地注销,就像使用 smtplib 一样,它使您能够看到客户端和服务器之间的每条消息。是否可以至少执行此操作或一些基本日志记录,如果可以,我该怎么做?我使用的代码是:

import email
from email.header import decode_header
from email import message_from_bytes
from email.policy import default
from aiosmtpd.controller import Controller
from aiosmtpd.smtp import LoginPassword, AuthResult
import os
import json
import re
import sys
import time
import signal 
import logging

from datetime import datetime
import configparser

##setting timezone
os.environ['TZ'] = "Europe/London"
time.tzset()

#wildlifeCameraHome = os.getenv('WILDLIFE_CAMERA_HOME')
wildlifeCameraHome = "/home/matthew_gale/smtp-server"

startupConfigURL = "{}/Config/Config.ini".format(wildlifeCameraHome)
validCameraList = "{}/Config/ValidCameraIDs.txt".format(wildlifeCameraHome)

ouboxBaseURL = "{}/outbox".format(wildlifeCameraHome)
spacer = "*"*100

# Get command line parameters
if len( sys.argv ) > 1 and str( sys.argv[1] ) == "DEBUG":
    debugMode = True
else:
    debugMode = False

if not debugMode:
    logFileURL = "{}/Logging/EmailExtractorLog.out".format(wildlifeCameraHome)
    sys.stdout = open(logFileURL, 'a', 1)
    sys.stderr = sys.stdout

if os.environ.get('VA_LOG_LEVEL') is None:
    envlevel = 3
else:
    envlevel = int(os.environ.get('VA_LOG_LEVEL'))

def Lprint(logstring, loglevel):
    detailedtimeStamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
    if loglevel <= envlevel or debugMode:
        print(detailedtimeStamp + ":" + logstring)
        return True
    else:
        return None

def onExit( sig, func=None):
    Lprint("*************Stopping program*****************",3)
    controller.stop()
    exit()
 
signal.signal(signal.SIGTERM, onExit)

# removes the spaces and replaces with _ so they're valid folder names
def clean(text):
    return "".join(c if c.isalnum() else "_" for c in text)


#get the configs from the config file
config = configparser.ConfigParser()
config.read(startupConfigURL)

gmailConfig = config['EmailExtractor']
validEmail = gmailConfig['validSender']

# check at the end if there's any validation regarding who sends the email
with open(validCameraList, 'r', encoding='utf-8') as f:
    validCameraIDs = f.readlines()

for rowNumber, content in enumerate(validCameraIDs): 
    validCameraIDs[rowNumber] = content.replace("\n","")

Lprint("Valid cameraIDs are",3)
print (validCameraIDs)

auth_db = {
    b"TestCamera1@gmail.com": b"password1",
    b"user2": b"password2",
    b"TestCamera1": b"password1",
}

def authenticator_func(server, session, envelope, mechanism, auth_data):
    # Simple auth - is only being used because of the reolink cam
    assert isinstance(auth_data, LoginPassword)
    username = auth_data.login
    password = auth_data.password
    if auth_db.get(username) == password:
        return AuthResult(success=True)
    else:
        return AuthResult(success=False, handled=False)   

def configure_logging():
    file_handler = logging.FileHandler("aiosmtpd.log", "a")
    stderr_handler = logging.StreamHandler(sys.stderr)
    logger = logging.getLogger("mail.log")
    fmt = "[%(asctime)s %(levelname)s] %(message)s"
    datefmt = None
    formatter = logging.Formatter(fmt, datefmt, "%")
    stderr_handler.setFormatter(stderr_handler)
    logger.addHandler(stderr_handler)
    file_handler.setFormatter(file_handler)
    logger.addHandler(file_handler)
    logger.setLevel(logging.DEBUG)    

class CustomHandler:
    def handle_exception(self, error):
        Lprint("exception occured",3)
        print(error)
        return '542 Internal Server Error'

    async def handle_DATA(self, server, session, envelope):
        peer = session.peer
        data = envelope.content         # type: bytes
        msg = message_from_bytes(envelope.content, policy=default)
        # decode the email subject
        Lprint("Msg:{}".format(msg),3)
        Lprint("Data:{}".format(data),3)
        Lprint("All of the relevant data has been extracted from the email",3)
        Lprint(spacer,3)
        return '250 OK'


if __name__ == '__main__':
    configure_logging()
    handler = CustomHandler()
    controller = Controller(handler, hostname='0.0.0.0', port=587, authenticator=authenticator_func, auth_required=True,auth_require_tls=False)    
    # Run the event loop in a separate thread.
    controller.start()
    #Confirmed that this is needed to keep the SMTP server running constantly
    while True:
        time.sleep(10)

如果您搜索 aiosmtpd codebase for "logging.getLogger", you can find a few places where logging is being configured with Python's standard logging module.

为了真正看到这些日志消息,您需要配置日志级别并添加日志处理程序。尝试在程序的早期调用以下“configure_logging”函数。它将设置基本日志记录到 stderr 和名为“aiosmtpd.log”的文件。完整示例:

import logging
import sys

def configure_logging():
    file_handler = logging.FileHandler("aiosmtpd.log", "a")
    stderr_handler = logging.StreamHandler(sys.stderr)
    logger = logging.getLogger("mail.log")
    fmt = "[%(asctime)s %(levelname)s] %(message)s"
    datefmt = None
    formatter = logging.Formatter(fmt, datefmt, "%")
    stderr_handler.setFormatter(formatter)
    logger.addHandler(stderr_handler)
    file_handler.setFormatter(formatter)
    logger.addHandler(file_handler)
    logger.setLevel(logging.DEBUG)

configure_logging()

# aiosmtpd example from 
import aiosmtpd.controller

class CustomSMTPHandler:
    async def handle_DATA(self, server, session, envelope):
        print(len(envelope.content), repr(envelope.content[:50]))
        return '250 OK'

handler = CustomSMTPHandler()
server = aiosmtpd.controller.Controller(handler, hostname="127.0.0.1")
server.start()
input("Server started. Press Return to quit.\n")
server.stop()

运行 在一个终端中执行上述脚本,然后在另一个终端中 运行 swaks --server '127.0.0.1:8025' --to foo@example.comSwiss Army Knife for SMTP)发送一封测试电子邮件,在终端上提供以下输出:

[2021-12-07 19:37:57,124 INFO] Available AUTH mechanisms: LOGIN(builtin) PLAIN(builtin)
[2021-12-07 19:37:57,124 INFO] Peer: ('127.0.0.1', 44126)
[2021-12-07 19:37:57,125 INFO] ('127.0.0.1', 44126) handling connection
[2021-12-07 19:37:57,125 DEBUG] ('127.0.0.1', 44126) << b'220 alcyone.localdomain Python SMTP 1.4.2'
Server started. Press Return to quit.
[2021-12-07 19:37:57,126 INFO] ('127.0.0.1', 44126) EOF received
[2021-12-07 19:37:57,126 INFO] ('127.0.0.1', 44126) Connection lost during _handle_client()
[2021-12-07 19:37:57,126 INFO] ('127.0.0.1', 44126) connection lost
[2021-12-07 19:38:02,012 INFO] Available AUTH mechanisms: LOGIN(builtin) PLAIN(builtin)
[2021-12-07 19:38:02,012 INFO] Peer: ('127.0.0.1', 44128)
[2021-12-07 19:38:02,013 INFO] ('127.0.0.1', 44128) handling connection
[2021-12-07 19:38:02,013 DEBUG] ('127.0.0.1', 44128) << b'220 alcyone.localdomain Python SMTP 1.4.2'
[2021-12-07 19:38:02,013 DEBUG] _handle_client readline: b'EHLO alcyone.localdomain\r\n'
[2021-12-07 19:38:02,013 INFO] ('127.0.0.1', 44128) >> b'EHLO alcyone.localdomain'
[2021-12-07 19:38:02,013 DEBUG] ('127.0.0.1', 44128) << b'250-alcyone.localdomain'
[2021-12-07 19:38:02,013 DEBUG] ('127.0.0.1', 44128) << b'250-SIZE 33554432'
[2021-12-07 19:38:02,013 DEBUG] ('127.0.0.1', 44128) << b'250-8BITMIME'
[2021-12-07 19:38:02,013 DEBUG] ('127.0.0.1', 44128) << b'250-SMTPUTF8'
[2021-12-07 19:38:02,013 DEBUG] ('127.0.0.1', 44128) << b'250 HELP'
[2021-12-07 19:38:02,014 DEBUG] _handle_client readline: b'MAIL FROM:<rav@alcyone.localdomain>\r\n'
[2021-12-07 19:38:02,014 INFO] ('127.0.0.1', 44128) >> b'MAIL FROM:<rav@alcyone.localdomain>'
[2021-12-07 19:38:02,014 INFO] ('127.0.0.1', 44128) sender: rav@alcyone.localdomain
[2021-12-07 19:38:02,014 DEBUG] ('127.0.0.1', 44128) << b'250 OK'
[2021-12-07 19:38:02,014 DEBUG] _handle_client readline: b'RCPT TO:<foo@example.com>\r\n'
[2021-12-07 19:38:02,014 INFO] ('127.0.0.1', 44128) >> b'RCPT TO:<foo@example.com>'
[2021-12-07 19:38:02,014 INFO] ('127.0.0.1', 44128) recip: foo@example.com
[2021-12-07 19:38:02,014 DEBUG] ('127.0.0.1', 44128) << b'250 OK'
[2021-12-07 19:38:02,014 DEBUG] _handle_client readline: b'DATA\r\n'
[2021-12-07 19:38:02,014 INFO] ('127.0.0.1', 44128) >> b'DATA'
[2021-12-07 19:38:02,015 DEBUG] ('127.0.0.1', 44128) << b'354 End data with <CR><LF>.<CR><LF>'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'Date: Tue, 07 Dec 2021 19:38:02 +0100\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'To: foo@example.com\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'From: rav@alcyone.localdomain\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'Subject: test Tue, 07 Dec 2021 19:38:02 +0100\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'Message-Id: <20211207193802.024948@alcyone.localdomain>\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'X-Mailer: swaks vDEVRELEASE jetmore.org/john/code/swaks/\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'This is a test mailing\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'\r\n'
[2021-12-07 19:38:02,015 DEBUG] DATA readline: b'.\r\n'
283 b'Date: Tue, 07 Dec 2021 19:38:02 +0100\r\nTo: foo@exa'
[2021-12-07 19:38:02,015 DEBUG] ('127.0.0.1', 44128) << b'250 OK'
[2021-12-07 19:38:02,015 DEBUG] _handle_client readline: b'QUIT\r\n'
[2021-12-07 19:38:02,015 INFO] ('127.0.0.1', 44128) >> b'QUIT'
[2021-12-07 19:38:02,015 DEBUG] ('127.0.0.1', 44128) << b'221 Bye'
[2021-12-07 19:38:02,016 INFO] ('127.0.0.1', 44128) connection lost
[2021-12-07 19:38:02,016 INFO] ('127.0.0.1', 44128) Connection lost during _handle_client()