[bug]: SMTP connection close early before receiving MAIL FROM and RCPT #700

winston0410 · 2024-08-20T15:05:48Z

winston0410
Aug 20, 2024

What happened?

I am trying to send a email from an external domain (I am using protonmail) to a self-hosted Stalwart instance. I noticed that the email bounced with a fail to deliver report like this:

<[bar@stalwartdomain.com](mailto:bar@stalwartdomain.com)>: host [bar@stalwartdomain.com](http://mail.stalwartdomain.com)[x.x.x.x] said:
    503 5.5.1 You must authenticate first. (in reply to MAIL FROM command)

----------------------------------------------
message/delivery-status
----------------------------------------------
Reporting-MTA: dns; [mail-43166.protonmail.ch](http://mail-43166.protonmail.ch/)
X-Postfix-Queue-ID: 4Wp7R71zSBz4wwdL
X-Postfix-Sender: rfc822; [foo@external.com](mailto:foo@external.com)
Arrival-Date: Tue, 20 Aug 2024 12:03:47 +0000 (UTC)

Final-Recipient: rfc822; [bar@stalwartdomain.com](mailto:bar@stalwartdomain.com)
Original-Recipient: [rfc822;bar@stalwartdomain.com](mailto:rfc822;bar@stalwartdomain.com)
Action: failed
Status: 5.5.1
Remote-MTA: dns; [mail.stalwartdomain.com](http://mail.stalwartdomain.com/)
Diagnostic-Code: smtp; 503 5.5.1 You must authenticate first.

Checking the log, I notice that MAIL FROM and RCPT is send from protonmail to Stalwart, but it seems like the connection is being closed already, sending 503 error code before receiving MAIL FROM and RCPT.

How can we reproduce the problem?

This is my stalwart configuration

[server.listener."smtp"]
bind = ["[::]:2025"]
protocol = "smtp"

# not sure if we need this
# https://stalw.art/docs/sieve/managesieve
[server.listener."sieve"]
bind = ["[::]:4190"]
protocol = "managesieve"
tls.implicit = true

[server.listener."submissions"]
bind = ["[::]:4465"]
protocol = "smtp"
tls.implicit = true

[server.listener."imap"]
bind = ["[::]:9143"]
protocol = "imap"

[server.listener."imaptls"]
bind = ["[::]:9993"]
protocol = "imap"
tls.implicit = true

[server.listener."http"]
bind = ["[::]:8080"]
protocol = "http"

[storage]
data = "postgresql"
fts = "postgresql"
blob = "s3"
lookup = "redis"
directory = "sql"

[storage.encryption]
enable = false
append = false

[directory."sql"]
type = "sql"
store = "postgresql"

[directory."sql".columns]
name = "name"
description = "description"
secret = "secret"
email = "address"
quota = "quota"
class = "type"

[store."postgresql"]
# omitted

[store."postgresql".query]
name = "SELECT name, type, secret, description, quota FROM accounts WHERE name = $1 AND active = true"
members = "SELECT member_of FROM group_members WHERE name = $1"
recipients = "SELECT name FROM emails WHERE address = $1 ORDER BY name ASC"
emails = "SELECT address FROM emails WHERE name = $1 AND type != 'list' ORDER BY type DESC, address ASC"
verify = "SELECT address FROM emails WHERE address LIKE '%' || $1 || '%' AND type = 'primary' ORDER BY address LIMIT 5"
expand = "SELECT p.address FROM emails AS p JOIN emails AS l ON p.name = l.name WHERE p.type = 'primary' AND l.address = $1 AND l.type = 'list' ORDER BY p.address LIMIT 50"
domains = "SELECT 1 FROM emails WHERE address LIKE '%@' || $1 LIMIT 1"

[store."postgresql".init]
execute = [
    "CREATE TABLE IF NOT EXISTS accounts (name TEXT PRIMARY KEY, secret TEXT, description TEXT, type TEXT NOT NULL, quota INTEGER DEFAULT 0, active BOOLEAN DEFAULT TRUE)",
    "CREATE TABLE IF NOT EXISTS group_members (name TEXT NOT NULL, member_of TEXT NOT NULL, PRIMARY KEY (name, member_of))",
    "CREATE TABLE IF NOT EXISTS emails (name TEXT NOT NULL, address TEXT NOT NULL, type TEXT, PRIMARY KEY (name, address))",
]

[store."s3"]
# omitted

[store."s3".purge]
frequency = "30 5 *"

[store."redis"]
# omitted

[tracer."stdout"]
type = "stdout"
level = "trace"
ansi = false
enable = true


[tracer.trace.enable]
log-exporter = false
span-exporter = true

[authentication]
rate-limit = "20/1m"

[authentication.fallback-admin]
# omitted

[authentication.master]
# omitted

[config.resource]
webadmin = "https://github.com/stalwartlabs/webadmin/releases/latest/download/webadmin.zip"

[lookup.default]
hostname = "mail.stalwartdomain.com"

[session]
timeout = "5m"
transfer-limit = 262144000 # 250 MB
duration = "10m"

[session.extensions]
pipelining = true
chunking = true
requiretls = false

[session.connect]
greeting = "'Stalwart ESMTP at your service'"

[session.ehlo]
require = true
reject-non-fqdn = [{ if = "listener = 'smtp'", then = true }, { else = false }]

[session.mail]

[session.rcpt]
directory = "'sql'"
relay = false
subaddressing = true

[session.auth]
allow-plain-text = false
must-match-sender = true

[session.auth.errors]
total = 3
wait = "5s"

[server.tls]
enable = true
implicit = false
timeout = "30s"
ignore-client-order = true

[certificate."default"]
cert = "%{file:/etc/stalwart-mail/ssl/tls.crt}%"
private-key = "%{file:/etc/stalwart-mail/ssl/tls.key}%"

[auth.arc]
verify = "relaxed"

[auth.dkim]
verify = "relaxed"

[auth.dmarc]
verify = "relaxed"

[auth.iprev]
verify = "disable"

[report.analysis]
forward = true

[queue.outbound.tls]
dane = "optional"
mta-sts = "optional"

And my K8S manifest(should be irrelavent here)

---
apiVersion: v1
automountServiceAccountToken: false
kind: ServiceAccount
metadata:
  name: default
  namespace: stalwart
---
apiVersion: v1
automountServiceAccountToken: false
kind: ServiceAccount
metadata:
  name: stalwart
  namespace: stalwart
---
apiVersion: cert-manager.io/v1
kind: Certificate
metadata:
  name: mail-tls
  namespace: stalwart
spec:
  secretName: mail-tls
  isCA: false
  privateKey:
    algorithm: RSA
    encoding: PKCS1
    size: 2048
  dnsNames:
    - "mail.stalwartdomain.com"
  issuerRef:
    name: "letsencrypt-production"
    kind: ClusterIssuer
---
apiVersion: apps/v1
kind: Deployment
metadata:
  labels:
    app.kubernetes.io/part-of: stalwart
    app.kubernetes.io/name: mailserver
  name: mailserver
  namespace: stalwart
spec:
  replicas: 1
  selector:
    matchLabels:
      app.kubernetes.io/part-of: stalwart
      app.kubernetes.io/name: mailserver
  template:
    metadata:
      labels:
        app.kubernetes.io/part-of: stalwart
        app.kubernetes.io/name: mailserver
    spec:
      automountServiceAccountToken: false
      serviceAccountName: stalwart
      securityContext:
        seccompProfile:
          type: RuntimeDefault
        fsGroup: 65534
      containers:
      - image: stalwartlabs/mail-server
        name: mail-server
        ports:
          - containerPort: 2025
            protocol: TCP
            name: smtp
          - containerPort: 4465
            protocol: TCP
            name: smtps
          - containerPort: 9143
            protocol: TCP
            name: imap
          - containerPort: 9993
            protocol: TCP
            name: imaps
          - containerPort: 8080
            protocol: TCP
            name: http
        livenessProbe:
          httpGet:
            path: /healthz/live
            port: 8080
          periodSeconds: 10
        readinessProbe:
          httpGet:
            path: /healthz/ready
            port: 8080
          periodSeconds: 10 
        volumeMounts:
          - name: tmp
            mountPath: /tmp
          - name: stalwart-cfg
            mountPath: /opt/stalwart-mail/etc
          - name: certificates
            mountPath: /etc/stalwart-mail/ssl
            readOnly: true
        resources:
          limits:
              cpu: 100m
              memory: 1024Mi
          requests:
              cpu: 10m
              memory: 256Mi
        securityContext:
          runAsNonRoot: true
          runAsGroup: 65534
          runAsUser: 65534
          allowPrivilegeEscalation: false
          readOnlyRootFilesystem: true
          capabilities:
            drop:
              - "ALL"
      volumes:
        - name: tmp
          emptyDir:
            sizeLimit: 256Mi
        - name: stalwart-cfg
          secret:
            secretName: stalwart-secret
        - name: certificates
          secret:
            secretName: mail-tls
            items:
              - key: tls.key
                path: tls.key
              - key: tls.crt
                path: tls.crt
---
apiVersion: v1
kind: Service
metadata:
  name: stalwart
  namespace: stalwart
  labels:
    app.kubernetes.io/part-of: stalwart
    app.kubernetes.io/name: mailserver
spec:
  ports:
    - name: http
      port: 80
      protocol: TCP
      targetPort: 8080

    - name: smtp
      port: 25
      protocol: TCP
      targetPort: 2025

    - name: smtps
      port: 465
      protocol: TCP
      targetPort: 4465

    - name: imap
      port: 143
      protocol: TCP
      targetPort: 9143

    - name: imaps
      port: 993
      protocol: TCP
      targetPort: 9993
  selector:
    app.kubernetes.io/part-of: stalwart
    app.kubernetes.io/name: mailserver
  type: ClusterIP
---
apiVersion: gateway.networking.k8s.io/v1
kind: HTTPRoute
metadata:
  name: stalwart
  namespace: stalwart
spec:
  parentRefs:
    - kind: Gateway
      name: tcp-gateway
      namespace: envoy-gateway
  hostnames:
    - "mail.stalwartdomain.com"
  rules:
    - matches:
        - path:
            type: PathPrefix
            value: /
      backendRefs:
        - name: stalwart
          namespace: stalwart
          port: 80
---
apiVersion: gateway.networking.k8s.io/v1alpha2
kind: TCPRoute
metadata:
  name: smtp
  namespace: stalwart
spec:
  parentRefs:
    - kind: Gateway
      name: tcp-gateway
      namespace: envoy-gateway
      sectionName: smtp
  rules:
    - backendRefs:
      - name: stalwart
        port: 25
---
apiVersion: gateway.networking.k8s.io/v1alpha2
kind: TCPRoute
metadata:
  name: imap
  namespace: stalwart
spec:
  parentRefs:
    - kind: Gateway
      name: tcp-gateway
      namespace: envoy-gateway
      sectionName: imap
  rules:
    - backendRefs:
      - name: stalwart
        port: 143
---
apiVersion: gateway.networking.k8s.io/v1alpha2
kind: TCPRoute
metadata:
  name: smtps
  namespace: stalwart
spec:
  parentRefs:
    - kind: Gateway
      name: tcp-gateway
      namespace: envoy-gateway
      sectionName: smtps
  rules:
    - backendRefs:
      - name: stalwart
        port: 465
---
apiVersion: gateway.networking.k8s.io/v1alpha2
kind: TCPRoute
metadata:
  name: imaps
  namespace: stalwart
spec:
  parentRefs:
    - kind: Gateway
      name: tcp-gateway
      namespace: envoy-gateway
      sectionName: imaps
  rules:
    - backendRefs:
      - name: stalwart
        port: 993

Version

v0.9.x

What database are you using?

PostgreSQL

What blob storage are you using?

S3-compatible

Where is your directory located?

SQL

What operating system are you using?

Docker

Relevant log output

2024-08-20T12:03:49Z INFO Network connection ended (network.connection-end) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, elapsed = 130ms, protocol = smtp
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 12, contents = "RSET\r\nQUIT\r\n"
	
	
2024-08-20T12:03:49Z DEBUG SMTP RSET command (smtp.rset) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 14, contents = "250 2.0.0 OK\r\n"
	
	
2024-08-20T12:03:49Z DEBUG SMTP QUIT command (smtp.quit) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 16, contents = "221 2.0.0 Bye.\r\n"
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 92, contents = "MAIL FROM:<foo@protonmail.com> SIZE=2267\r\nRCPT TO:<bar@stalwartdomain.com>\r\nDATA\r\n"
	
	
2024-08-20T12:03:49Z DEBUG MAIL FROM unauthenticated (smtp.mail-from-unauthenticated) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 40, contents = "503 5.5.1 You must authenticate first.\r\n"
	
	
2024-08-20T12:03:49Z DEBUG MAIL FROM address missing (smtp.mail-from-missing) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 35, contents = "503 5.5.1 MAIL is required first.\r\n"
	
	
2024-08-20T12:03:49Z DEBUG RCPT TO address missing (smtp.rcpt-to-missing) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 35, contents = "503 5.5.1 RCPT is required first.\r\n"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.future-release", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.future-release", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.deliver-by", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.deliver-by", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.mt-priority", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.mt-priority", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.data.limits.size", result = "Integer(104857600)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.no-soliciting", result = "String("")"
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 207, contents = "250-mail.stalwartdomain.com you had me at EHLO\r\n250-SMTPUTF8\r\n250-SIZE 104857600\r\n250-PIPELINING\r\n250-NO-SOLICITING\r\n250-ENHANCEDSTATUSCODES\r\n250-CHUNKING\r\n250-BINARYMIME\r\n250-AUTH PLAIN LOGIN\r\n250 8BITMIME\r\n"
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 31, contents = "EHLO mail-43166.protonmail.ch\r\n"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.pipelining", result = "Integer(1)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.chunking", result = "Integer(1)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.expn", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.vrfy", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.requiretls", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.dsn", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.auth.mechanisms", result = "Array([Integer(1099511627776), Integer(549755813888)])"
	
	
2024-08-20T12:03:49Z INFO TLS handshake (tls.handshake) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, listenerId = "smtp", protocol = smtp, version = "TLSv1_3", details = "TLS13_AES_256_GCM_SHA384"
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 10, contents = "STARTTLS\r\n"
	
	
2024-08-20T12:03:49Z DEBUG SMTP STARTTLS command (smtp.start-tls) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 31, contents = "220 2.0.0 Ready to start TLS.\r\n"
	
	
2024-08-20T12:03:49Z INFO SMTP EHLO command (smtp.ehlo) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, domain = "mail-43166.protonmail.ch"
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 31, contents = "EHLO mail-43166.protonmail.ch\r\n"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.ehlo.script", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.pipelining", result = "Integer(1)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.chunking", result = "Integer(1)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.expn", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.vrfy", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.requiretls", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.dsn", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.auth.mechanisms", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.future-release", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.future-release", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.deliver-by", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.deliver-by", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.mt-priority", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.mt-priority", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.data.limits.size", result = "Integer(104857600)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.no-soliciting", result = "String("")"
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 199, contents = "250-mail.stalwartdomain.com you had me at EHLO\r\n250-STARTTLS\r\n250-SMTPUTF8\r\n250-SIZE 104857600\r\n250-PIPELINING\r\n250-NO-SOLICITING\r\n250-ENHANCEDSTATUSCODES\r\n250-CHUNKING\r\n250-BINARYMIME\r\n250 8BITMIME\r\n"
	
	
2024-08-20T12:03:49Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, size = 36, contents = "220 Stalwart ESMTP at your service\r\n"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.expn", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.extensions.vrfy", result = "Integer(0)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.connect.script", result =
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "server.connect.hostname", result = "String("mail.stalwartdomain.com")"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.connect.greeting", result = "String("Stalwart ESMTP at your service")"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.auth.errors.total", result = "Integer(3)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.auth.errors.wait", result = "Integer(5000)"
	
	
2024-08-20T12:03:49Z INFO Network connection started (network.connection-start) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.transfer-limit", result = "Integer(262144000)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.duration", result = "Integer(600000)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.timeout", result = "Integer(300000)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "auth.spf.verify.ehlo", result = "Integer(4)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "auth.spf.verify.mail-from", result = "Integer(4)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "auth.iprev.verify", result = "Integer(4)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.ehlo.require", result = "Integer(1)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.ehlo.reject-non-fqdn", result = "Integer(1)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.auth.directory", result = "String("*")"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.auth.require", result = "Integer(1)"
	
	
2024-08-20T12:03:49Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59010, id = "session.auth.must-match-sender", result = "Integer(1)"
	
	
2024-08-20T12:03:45Z INFO Network connection ended (network.connection-end) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, elapsed = 53ms, protocol = smtp
	
	
2024-08-20T12:03:45Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, size = 16, contents = "221 2.0.0 Bye.\r\n"
	
	
2024-08-20T12:03:45Z DEBUG SMTP QUIT command (smtp.quit) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000
	
	
2024-08-20T12:03:45Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, size = 6, contents = "QUIT\r\n"
	
	
2024-08-20T12:03:45Z INFO Authentication not allowed (smtp.auth-not-allowed) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000
	
	
2024-08-20T12:03:45Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, size = 12, contents = "AUTH LOGIN\r\n"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.auth.mechanisms", result = "Integer(0)"
	
	
2024-08-20T12:03:45Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, size = 29, contents = "503 5.5.1 AUTH not allowed.\r\n"
	
	
2024-08-20T12:03:45Z INFO Invalid EHLO command (smtp.invalid-ehlo) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, domain = "User"
	
	
2024-08-20T12:03:45Z TRACE Raw SMTP input received (smtp.raw-input) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, size = 11, contents = "EHLO User\r\n"
	
	
2024-08-20T12:03:45Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, size = 32, contents = "550 5.5.0 Invalid EHLO domain.\r\n"
	
	
2024-08-20T12:03:45Z TRACE Raw SMTP output sent (smtp.raw-output) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, size = 36, contents = "220 Stalwart ESMTP at your service\r\n"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.auth.errors.total", result = "Integer(3)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.auth.errors.wait", result = "Integer(5000)"
	
	
2024-08-20T12:03:45Z INFO Network connection started (network.connection-start) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.transfer-limit", result = "Integer(262144000)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.duration", result = "Integer(600000)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.timeout", result = "Integer(300000)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "auth.spf.verify.ehlo", result = "Integer(4)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "auth.spf.verify.mail-from", result = "Integer(4)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "auth.iprev.verify", result = "Integer(4)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.ehlo.require", result = "Integer(1)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.ehlo.reject-non-fqdn", result = "Integer(1)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.auth.directory", result = "String("*")"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.auth.require", result = "Integer(1)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.auth.must-match-sender", result = "Integer(1)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.extensions.expn", result = "Integer(0)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.extensions.vrfy", result = "Integer(0)"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.connect.script", result =
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "server.connect.hostname", result = "String("mail.stalwartdomain.com")"
	
	
2024-08-20T12:03:45Z TRACE Expression evaluation result (eval.result) listenerId = "smtp", protocol = smtp, remoteIp = 10.244.0.33, remotePort = 59000, id = "session.connect.greeting", result = "String("Stalwart ESMTP at your service")"

Code of Conduct

I agree to follow this project's Code of Conduct

Answered by mdecimus

Aug 20, 2024

Since you haven't specified a value for the session.require.auth key it is using the default which is:

[session.auth]
require = [ { if = "local_port != 25", then = true},
            { else = false } ]

You need to update it to use your custom port instead.

View full answer

mdecimus · 2024-08-20T17:07:09Z

mdecimus
Aug 20, 2024
Maintainer

Since you haven't specified a value for the session.require.auth key it is using the default which is:

[session.auth]
require = [ { if = "local_port != 25", then = true},
            { else = false } ]

You need to update it to use your custom port instead.

1 reply

winston0410 Aug 21, 2024
Author

Thanks that solved my issue. At the end I used this:

[session.auth]
mechanisms = [ { if = "listener != 'smtp'", then = "[plain, login]"},
            { else = false } ]

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[bug]: SMTP connection close early before receiving MAIL FROM and RCPT #700

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 1 comment 1 reply

{{title}}

{{title}}

Select a reply

[bug]: SMTP connection close early before receiving MAIL FROM and RCPT #700

winston0410 Aug 20, 2024

What happened?

How can we reproduce the problem?

Version

What database are you using?

What blob storage are you using?

Where is your directory located?

What operating system are you using?

Relevant log output

Code of Conduct

Replies: 1 comment · 1 reply

mdecimus Aug 20, 2024 Maintainer

winston0410 Aug 21, 2024 Author

winston0410
Aug 20, 2024

Replies: 1 comment 1 reply

mdecimus
Aug 20, 2024
Maintainer

winston0410 Aug 21, 2024
Author