带有基本日志记录的服务器

Question

我知道aiosmtpd会登录到syslog。我正在使用related发行版，在消息或邮件日志文件中找不到任何与我的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)

Answer 1

如果您在aiosmtpd代码基酶中搜索"logging.getLogger"，您可以找到一个 一些 地点，其中使用Python的标准测井模块配置日志记录。

为了实际查看这些日志消息，需要配置日志级别并添加日志处理程序。尝试在程序的早期调用以下"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 https://stackoverflow.com/a/43904837/1570972
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.com ( 用于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()