Skip to content

Instantly share code, notes, and snippets.

@kyrias

kyrias/backtrace

Created November 12, 2019 18:28
Show Gist options
  • Save kyrias/0884179946a954926bbb2241b429b9a5 to your computer and use it in GitHub Desktop.
Save kyrias/0884179946a954926bbb2241b429b9a5 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
backtrace
#0 0x00007f0c3b209bfe in __strcmp_avx2 () from /usr/lib/libc.so.6
#1 0x000055fbe0ca1399 in dictentry_cmp (a=0x7ffe440d98e0, b=<optimized out>) at ../../smtpd/dict.c:266
#2 _dict_SPLAY (head=head@entry=0x55fbe16710d0, elm=elm@entry=0x7ffe440d98e0) at ../../smtpd/dict.c:269
#3 0x000055fbe0ca17ec in _dict_SPLAY_FIND (elm=0x7ffe440d98e0, head=0x55fbe16710d0) at ../../smtpd/dict.c:40
#4 dict_get (d=0x55fbe16710d0, k=<optimized out>) at ../../smtpd/dict.c:107
#5 0x000055fbe0cd7b6d in table_find (conf=<optimized out>, name=<optimized out>) at ../../smtpd/table.c:110
#6 0x000055fbe0cc9013 in ruleset_match_from (evp=0x7ffe440daaa0, r=0x55fbe1697d20) at ../../smtpd/ruleset.c:96
#7 ruleset_match (evp=evp@entry=0x7ffe440daaa0) at ../../smtpd/ruleset.c:237
#8 0x000055fbe0cad521 in lka_expand (lks=lks@entry=0x55fbe1698480, rule=<optimized out>, xn=0x55fbe169a190) at ../../smtpd/lka_session.c:319
#9 0x000055fbe0cad853 in lka_resume (lks=0x55fbe1698480) at ../../smtpd/lka_session.c:204
#10 0x000055fbe0cadbbd in lka_session (id=12039383155050611034, envelope=envelope@entry=0x7ffe440ddfd0) at ../../smtpd/lka_session.c:102
#11 0x000055fbe0ca8f59 in lka_imsg (p=<optimized out>, imsg=<optimized out>) at ../../smtpd/lka.c:150
#12 0x000055fbe0cd433e in imsg_dispatch (p=0x55fbe172afb0, imsg=0x7ffe440e0940) at ../../smtpd/smtpd.c:1851
#13 0x000055fbe0cb1976 in mproc_dispatch (fd=<optimized out>, event=<optimized out>, arg=0x55fbe172afb0) at ../../smtpd/mproc.c:208
#14 0x00007f0c3b5092ce in ?? () from /usr/lib/libevent-2.1.so.7
#15 0x00007f0c3b509b7f in event_base_loop () from /usr/lib/libevent-2.1.so.7
#16 0x000055fbe0ca9c4f in lka () at ../../smtpd/lka.c:721
#17 0x000055fbe0c99ba0 in main (argc=<optimized out>, argv=<optimized out>) at ../../smtpd/smtpd.c:821
Raw
smtpd log with censored emails
debug: init ssl-tree
info: loading pki information for theos.kyriasis.com
debug: init ca-tree
debug: init ssl-tree
info: loading pki keys for theos.kyriasis.com
debug: using "fs" queue backend
debug: using "ramqueue" scheduler backend
debug: using "ram" stat backend
info: OpenSMTPD 6.6.1p1 starting
debug: init ssl-tree
info: loading pki information for theos.kyriasis.com
debug: init ca-tree
debug: init ssl-tree
info: loading pki keys for theos.kyriasis.com
debug: using "fs" queue backend
debug: using "ramqueue" scheduler backend
debug: using "ram" stat backend
setup_peer: klondike -> control[2254732] fd=4
setup_peer: klondike -> pony express[2254734] fd=5
setup_proc: klondike done
setup_done: ca[2254731] done
mproc: ca -> control: enabled
mproc: ca -> parent: enabled
mproc: ca -> pony: enabled
mproc: ca -> pony: disabled
debug: init ssl-tree
info: loading pki information for theos.kyriasis.com
debug: init ca-tree
debug: init ssl-tree
info: loading pki keys for theos.kyriasis.com
debug: using "fs" queue backend
debug: using "ramqueue" scheduler backend
debug: using "ram" stat backend
setup_peer: scheduler -> control[2254732] fd=4
setup_peer: scheduler -> queue[2254735] fd=5
debug: init ssl-tree
info: loading pki information for theos.kyriasis.com
debug: init ca-tree
debug: init ssl-tree
info: loading pki keys for theos.kyriasis.com
debug: using "fs" queue backend
debug: using "ramqueue" scheduler backend
debug: using "ram" stat backend
setup_peer: control -> klondike[2254731] fd=4
setup_peer: control -> lookup[2254733] fd=5
setup_peer: control -> pony express[2254734] fd=6
setup_peer: control -> queue[2254735] fd=7
setup_peer: control -> scheduler[2254736] fd=8
setup_proc: control done
ramstat: init
ramstat: set: uptime
ramstat: uptime: n/a -> n/a
mproc: control -> scheduler: enabled
mproc: control -> queue: enabled
mproc: control -> parent: enabled
mproc: control -> lka: enabled
mproc: control -> pony: enabled
mproc: control -> ca: enabled
setup_done: control[2254732] done
debug: init ssl-tree
info: loading pki information for theos.kyriasis.com
debug: init ca-tree
debug: init ssl-tree
info: loading pki keys for theos.kyriasis.com
debug: using "fs" queue backend
debug: using "ramqueue" scheduler backend
debug: using "ram" stat backend
setup_peer: lookup -> control[2254732] fd=4
setup_peer: lookup -> pony express[2254734] fd=5
setup_peer: lookup -> queue[2254735] fd=6
setup_done: lka[2254733] done
setup_proc: lookup done
debug: init ssl-tree
info: loading pki information for theos.kyriasis.com
debug: init ca-tree
debug: init ssl-tree
info: loading pki keys for theos.kyriasis.com
debug: using "fs" queue backend
debug: using "ramqueue" scheduler backend
debug: using "ram" stat backend
setup_peer: queue -> control[2254732] fd=4
setup_peer: queue -> pony express[2254734] fd=5
setup_peer: queue -> lookup[2254733] fd=6
setup_peer: queue -> scheduler[2254736] fd=7
debug: init ssl-tree
info: loading pki information for theos.kyriasis.com
debug: init ca-tree
debug: init ssl-tree
info: loading pki keys for theos.kyriasis.com
debug: using "fs" queue backend
debug: using "ramqueue" scheduler backend
debug: using "ram" stat backend
setup_peer: pony express -> control[2254732] fd=4
setup_peer: pony express -> klondike[2254731] fd=5
setup_peer: pony express -> lookup[2254733] fd=6
setup_peer: pony express -> queue[2254735] fd=7
setup_proc: pony express done
mproc: pony -> parent: enabled
mproc: pony -> queue: enabled
mproc: pony -> lka: enabled
mproc: pony -> control: enabled
mproc: pony -> ca: enabled
debug: rsa_engine_init: using RSA privsep engine
debug: ecdsa_engine_init: using ECDSA privsep engine
setup_done: pony[2254734] done
setup_proc: queue done
setup_done: queue[2254735] done
setup_proc: scheduler done
debug: bounce warning after 4h
mproc: scheduler -> control: enabled
mproc: scheduler -> queue: enabled
scheduler: getting batch: mask=0x1f, count=10
debug: /--- ramqueue: scheduler_ram_batch()
debug: \---
scheduler: got r=0, delay=-1, count=10
scheduler: sleeping
mproc: lka -> parent: enabled
mproc: lka -> queue: enabled
mproc: lka -> control: enabled
mproc: lka -> pony: enabled
mproc: lka -> pony: disabled
setup_done: scheduler[2254736] done
smtpd: setup done
mproc: parent -> control: enabled
mproc: parent -> lka: enabled
mproc: parent -> queue: enabled
mproc: parent -> ca: enabled
mproc: parent -> pony: enabled
debug: parent_send_config_ruleset: reloading
mproc: parent -> lka : 0 IMSG_CONF_START
mproc: parent -> lka : 0 IMSG_CONF_END
debug: parent_send_config: configuring pony process
mproc: parent -> pony : 0 IMSG_CONF_START
mproc: parent -> pony : 0 IMSG_CONF_END
debug: parent_send_config: configuring ca process
mproc: parent -> ca : 0 IMSG_CONF_START
mproc: parent -> ca : 0 IMSG_CONF_END
imsg: lka <- parent: IMSG_CONF_START (len=0)
imsg: lka <- parent: IMSG_CONF_END (len=0)
TABLE "<anydestination>" backend=static type=LIST
"*"
"theos"
TABLE "<anyhost>" backend=static type=LIST
"0.0.0.0/0"
"::/0"
"local"
TABLE "<dynamic:0>" backend=static type=LIST
"smtp://127.0.0.1:10025"
TABLE "<dynamic:1>" backend=static type=LIST
"smtp://127.0.0.1:10030"
TABLE "<dynamic:2>" backend=static type=LIST
"smtp://127.0.0.1:10027"
TABLE "<dynamic:3>" backend=static type=LIST
"from-external"
TABLE "<dynamic:4>" backend=static type=LIST
"from-external"
TABLE "<dynamic:5>" backend=static type=LIST
"from-dkimproxy-in"
TABLE "<dynamic:6>" backend=static type=LIST
"from-spampd"
TABLE "<dynamic:7>" backend=static type=LIST
"from-spampd"
TABLE "<dynamic:8>" backend=static type=LIST
"from-submission"
TABLE "<dynamic:9>" backend=static type=LIST
"from-dkimproxy-out"
TABLE "<getpwnam>" backend=getpwnam type=DYNAMIC
TABLE "<localhost>" backend=static type=LIST
"127.0.0.1"
"212.71.254.33"
"[2a01:7e00::f03c:91ff:fe6e:f996]"
"[2a01:7e00:e000:136::1]"
"[::1]"
"[fe80::f03c:91ff:fe6e:f996]"
"local"
TABLE "<localnames>" backend=static type=LIST
"127.0.0.1"
"212.71.254.33"
"[127.0.0.1]"
"[212.71.254.33]"
"[2a01:7e00::f03c:91ff:fe6e:f996]"
"[2a01:7e00:e000:136::1]"
"[::1]"
"[[2a01:7e00::f03c:91ff:fe6e:f996]]"
"[[2a01:7e00:e000:136::1]]"
"[[::1]]"
"[[fe80::f03c:91ff:fe6e:f996]]"
"[fe80::f03c:91ff:fe6e:f996]"
"[ipv6:[2a01:7e00::f03c:91ff:fe6e:f996]]"
"[ipv6:[2a01:7e00:e000:136::1]]"
"[ipv6:[::1]]"
"[ipv6:[fe80::f03c:91ff:fe6e:f996]]"
"localhost"
"theos.kyriasis.com"
TABLE "allowed-senders" backend=static type=HASH config="/etc/smtpd/table-senders"
"foo1" -> "[email protected],[email protected]"
"foo2" -> "[email protected],[email protected]"
"kyrias" -> "@kyriasis.com,@remmy.io,@theos.kyriasis.com"
"foo3" -> "[email protected],[email protected],@lucifer.kyriasis.com"
"foo4" -> "[email protected],[email protected],[email protected]"
TABLE "backup-domains" backend=static type=LIST config="/etc/smtpd/table-domains-backup"
"lucifer.kyriasis.com"
TABLE "primary-domains" backend=static type=LIST config="/etc/smtpd/table-domains-primary"
"kyriasis.com"
"remmy.io"
"theos.kyriasis.com"
TABLE "users" backend=static type=HASH config="/etc/smtpd/table-users"
"@kyriasis.com" -> "kyrias"
"@lists.kyriasis.com" -> "lists"
"@remmy.io" -> "kyrias"
"foo3" -> "[email protected]"
"foo3" -> "[email protected]"
"foo1" -> "foo1"
"foo2" -> "foo2"
"kyrias" -> "kyrias"
"foo4" -> "[email protected]"
"foo3" -> "[email protected]"
"foo5" -> "[email protected]"
"foo5" -> "[email protected]"
imsg: ca <- parent: IMSG_CONF_START (len=0)
"foo4" -> "[email protected]"
"foo4" -> "[email protected]"
imsg: ca <- parent: IMSG_CONF_END (len=0)
debug: init private ssl-tree
imsg: pony <- parent: IMSG_CONF_START (len=0)
imsg: pony <- parent: IMSG_CONF_END (len=0)
debug: smtp: listen on 212.71.254.33 port 25 flags 0x401 pki "theos.kyriasis.com" ca ""
mproc: ca -> pony: enabled
debug: smtp: listen on [2a01:7e00::f03c:91ff:fe6e:f996] port 25 flags 0x401 pki "theos.kyriasis.com" ca ""
debug: smtp: listen on [2a01:7e00:e000:136::1] port 25 flags 0x401 pki "theos.kyriasis.com" ca ""
debug: smtp: listen on [fe80::f03c:91ff:fe6e:f996] port 25 flags 0x401 pki "theos.kyriasis.com" ca ""
debug: smtp: listen on 127.0.0.1 port 10026 flags 0x400 pki "" ca ""
debug: smtp: listen on [::1] port 10026 flags 0x400 pki "" ca ""
debug: smtp: listen on 127.0.0.1 port 10031 flags 0x400 pki "" ca ""
debug: smtp: listen on [::1] port 10031 flags 0x400 pki "" ca ""
debug: smtp: listen on 127.0.0.1 port 25 flags 0x1c00 pki "" ca ""
debug: smtp: listen on [::1] port 25 flags 0x1c00 pki "" ca ""
debug: smtp: listen on 212.71.254.33 port 587 flags 0x1c69 pki "theos.kyriasis.com" ca ""
debug: smtp: listen on [2a01:7e00::f03c:91ff:fe6e:f996] port 587 flags 0x1c69 pki "theos.kyriasis.com" ca ""
debug: smtp: listen on [2a01:7e00:e000:136::1] port 587 flags 0x1c69 pki "theos.kyriasis.com" ca ""
debug: smtp: listen on [fe80::f03c:91ff:fe6e:f996] port 587 flags 0x1c69 pki "theos.kyriasis.com" ca ""
debug: smtp: listen on 127.0.0.1 port 10028 flags 0x400 pki "" ca ""
debug: smtp: listen on [::1] port 10028 flags 0x400 pki "" ca ""
debug: pony: rsae_init
debug: pony: rsae_init
debug: smtp: will accept at most 262139 clients
queue-backend: queue_init(1) -> 1
mproc: queue -> parent: enabled
mproc: queue -> control: enabled
mproc: queue -> lka: enabled
mproc: queue -> scheduler: enabled
mproc: queue -> pony: enabled
mproc: lka -> pony: enabled
queue-backend: queue_envelope_walk() -> 379 (3a49b3874e28281a)
mproc: queue -> control: realloc 0 -> 128
mproc: queue -> control : 53 IMSG_STAT_INCREMENT
mproc: queue -> scheduler: realloc 0 -> 128
mproc: queue -> scheduler: realloc 128 -> 512
mproc: queue -> scheduler : 389 IMSG_QUEUE_ENVELOPE_SUBMIT
imsg: scheduler <- queue: IMSG_QUEUE_ENVELOPE_SUBMIT (len=389)
scheduler: inserting evp:3a49b3874e28281a
mproc: scheduler -> control: realloc 0 -> 128
mproc: scheduler -> control : 61 IMSG_STAT_INCREMENT
mproc: scheduler -> control : 59 IMSG_STAT_INCREMENT
mproc: scheduler -> control : 60 IMSG_STAT_INCREMENT
mproc: scheduler -> control : 61 IMSG_STAT_INCREMENT
imsg: control <- queue: IMSG_STAT_INCREMENT (len=53)
ramstat: increment: queue.evpcache.size
ramstat: queue.evpcache.size (0x560e303ad0a1): 0 -> 1
imsg: control <- scheduler: IMSG_STAT_INCREMENT (len=61)
ramstat: increment: scheduler.envelope.incoming
ramstat: scheduler.envelope.incoming (0x560e30423a71): 0 -> 1
imsg: control <- scheduler: IMSG_STAT_INCREMENT (len=59)
ramstat: increment: scheduler.ramqueue.update
ramstat: scheduler.ramqueue.update (0x560e30423a71): 0 -> 1
imsg: control <- scheduler: IMSG_STAT_INCREMENT (len=60)
ramstat: increment: scheduler.ramqueue.message
ramstat: scheduler.ramqueue.message (0x560e30423a71): 0 -> 1
imsg: control <- scheduler: IMSG_STAT_INCREMENT (len=61)
ramstat: increment: scheduler.ramqueue.envelope
ramstat: scheduler.ramqueue.envelope (0x560e30423a71): 0 -> 1
queue-backend: queue_envelope_walk() -> -1 (0000000000000000)
mproc: queue -> scheduler : 4 IMSG_QUEUE_MESSAGE_COMMIT
debug: queue: done loading queue into scheduler
imsg: scheduler <- queue: IMSG_QUEUE_MESSAGE_COMMIT (len=4)
scheduler: committing msg:3a49b387
debug: /--- ramqueue: update to commit
debug: | msg:3a49b387
debug: | evp:3a49b3874e28281a [mta,expire=3d13h18s,pending=-10h59m42s]
debug: \---
debug: /--- ramqueue: resulting queue
debug: | msg:3a49b387
debug: | evp:3a49b3874e28281a [mta,expire=3d13h18s,pending=-10h59m42s]
debug: \---
mproc: scheduler -> control : 59 IMSG_STAT_DECREMENT
mproc: scheduler -> control : 61 IMSG_STAT_DECREMENT
mproc: scheduler -> control : 52 IMSG_STAT_INCREMENT
scheduler: getting batch: mask=0x1f, count=10
debug: /--- ramqueue: scheduler_ram_batch()
debug: | msg:3a49b387
debug: | evp:3a49b3874e28281a [mta,expire=3d13h18s,scheduled=0s]
debug: \---
scheduler: got r=0, delay=-1, count=10
scheduler: sleeping
imsg: control <- scheduler: IMSG_STAT_DECREMENT (len=59)
ramstat: decrement: scheduler.ramqueue.update
ramstat: scheduler.ramqueue.update (0x560e30423a71): 1 -> 0
imsg: control <- scheduler: IMSG_STAT_DECREMENT (len=61)
ramstat: decrement: scheduler.envelope.incoming
ramstat: scheduler.envelope.incoming (0x560e30423a71): 1 -> 0
imsg: control <- scheduler: IMSG_STAT_INCREMENT (len=52)
ramstat: increment: scheduler.envelope
ramstat: scheduler.envelope (0x560e303ad0a1): 0 -> 1
debug: smtpd: scanning offline queue...
debug: smtpd: offline scanning done
mproc: control -> client-proc: enabled
ramstat: increment: control.session
ramstat: control.session (0x560e2edf01b2): 0 -> 1
info: mta resumed
mproc: control -> queue : 0 IMSG_CTL_RESUME_MTA
mproc: control -> client-proc : 0 IMSG_CTL_OK
imsg: queue <- control: IMSG_CTL_RESUME_MTA (len=0)
mproc: queue -> scheduler : 0 IMSG_CTL_RESUME_MTA (forward)
imsg: scheduler <- queue: IMSG_CTL_RESUME_MTA (len=0)
scheduler: resuming mta
scheduler: getting batch: mask=0x3f, count=10
debug: /--- ramqueue: scheduler_ram_batch()
debug: | msg:3a49b387
debug: | evp:3a49b3874e28281a [mta,expire=3d13h10s,scheduled=8s]
debug: \---
scheduler: got r=1, delay=22079, count=1
debug: scheduler: evp:3a49b3874e28281a scheduled (mta)
mproc: scheduler -> queue: realloc 0 -> 128
mproc: scheduler -> queue : 8 IMSG_SCHED_ENVELOPE_TRANSFER
mproc: scheduler -> control : 61 IMSG_STAT_INCREMENT
scheduler: getting batch: mask=0x3f, count=10
debug: /--- ramqueue: scheduler_ram_batch()
debug: | msg:3a49b387
debug: | evp:3a49b3874e28281a [mta,expire=3d13h10s,inflight=0s]
debug: \---
scheduler: got r=0, delay=-1, count=10
scheduler: sleeping
debug: control -> client: pipe closed
debug: clearing p=client, fd=13, pid=0
ramstat: decrement: control.session
ramstat: control.session (0x560e2edf01b2): 1 -> 0
imsg: control <- scheduler: IMSG_STAT_INCREMENT (len=61)
ramstat: increment: scheduler.envelope.inflight
ramstat: scheduler.envelope.inflight (0x560e303b0e11): 0 -> 1
imsg: queue <- scheduler: IMSG_SCHED_ENVELOPE_TRANSFER (len=8)
mproc: queue -> control : 57 IMSG_STAT_INCREMENT
mproc: queue -> pony: realloc 0 -> 128
mproc: queue -> pony: realloc 128 -> 512
mproc: queue -> pony : 398 IMSG_QUEUE_TRANSFER
imsg: pony <- queue: IMSG_QUEUE_TRANSFER (len=398)
debug: mta: querying smarthost for to-dkimproxy-out:<dynamic:2>...
mproc: pony -> lka: realloc 0 -> 128
mproc: pony -> lka : 21 IMSG_MTA_LOOKUP_SMARTHOST
debug: mta: querying smarthost
imsg: lka <- pony: IMSG_MTA_LOOKUP_SMARTHOST (len=21)
mproc: lka -> pony: realloc 0 -> 128
lookup: fetch RELAYHOST from table static:<dynamic:2> -> "smtp://127.0.0.1:10027"
mproc: lka -> pony : 36 IMSG_MTA_LOOKUP_SMARTHOST
imsg: pony <- lka: IMSG_MTA_LOOKUP_SMARTHOST (len=36)
debug: mta: ... got smarthost for 3a49b3874e28281a: smtp://127.0.0.1:10027
mproc: pony -> control: realloc 0 -> 128
mproc: pony -> control : 44 IMSG_STAT_INCREMENT
mproc: pony -> control : 43 IMSG_STAT_INCREMENT
mproc: pony -> control : 42 IMSG_STAT_INCREMENT
debug: mta: received evp:3a49b3874e28281a for <[email protected]>
mproc: pony -> control : 46 IMSG_STAT_INCREMENT
debug: mta: draining [relay:127.0.0.1,port=10027,smtp,mx] refcount=1, ntask=1, nconnector=0, nconn=0
debug: mta: querying MX for [relay:127.0.0.1,port=10027,smtp,mx]...
mproc: pony -> lka : 19 IMSG_MTA_DNS_HOST
debug: mta: [relay:127.0.0.1,port=10027,smtp,mx] waiting for MX
imsg: lka <- pony: IMSG_MTA_DNS_HOST (len=19)
mproc: lka -> pony : 47 IMSG_MTA_DNS_HOST
mproc: lka -> pony : 12 IMSG_MTA_DNS_HOST_END
imsg: pony <- lka: IMSG_MTA_DNS_HOST (len=47)
mproc: pony -> control : 42 IMSG_STAT_INCREMENT
imsg: pony <- lka: IMSG_MTA_DNS_HOST_END (len=12)
debug: MXs for domain 127.0.0.1:
127.0.0.1 preference -1
debug: mta: ... got mx (0x5636709cd8d0, 127.0.0.1, [relay:127.0.0.1,port=10027,smtp,mx])
debug: mta: draining [relay:127.0.0.1,port=10027,smtp,mx] refcount=1, ntask=1, nconnector=0, nconn=0
debug: mta: querying source for [relay:127.0.0.1,port=10027,smtp,mx]...
mproc: pony -> control : 44 IMSG_STAT_INCREMENT
debug: mta: ... got source for [relay:127.0.0.1,port=10027,smtp,mx]: []
mproc: pony -> control : 47 IMSG_STAT_INCREMENT
debug: mta: new [connector:[]->[relay:127.0.0.1,port=10027,smtp,mx],0x10000]
debug: mta: connecting with [connector:[]->[relay:127.0.0.1,port=10027,smtp,mx],0x0]
debug: mta-routing: searching new route for [connector:[]->[relay:127.0.0.1,port=10027,smtp,mx],0x0]...
mproc: pony -> control : 43 IMSG_STAT_INCREMENT
debug: mta-routing: selecting candidate route [] <-> 127.0.0.1
debug: mta-routing: spawning new connection on [] <-> 127.0.0.1
debug: mta: 0x5636709cf480: spawned for relay [relay:127.0.0.1,port=10027,smtp,mx]
mproc: pony -> control : 45 IMSG_STAT_INCREMENT
mproc: pony -> lka : 28 IMSG_GETNAMEINFO
debug: mta: connecting with [connector:[]->[relay:127.0.0.1,port=10027,smtp,mx],0x0]
debug: mta: cannot use [relay:127.0.0.1,port=10027,smtp,mx] before 2s
debug: mta-routing: no route available for [connector:[]->[relay:127.0.0.1,port=10027,smtp,mx],0x0]: must wait a bit
debug: mta: retrying to connect on [connector:[]->[relay:127.0.0.1,port=10027,smtp,mx],0x0] in 2s...
debug: mta: draining [relay:127.0.0.1,port=10027,smtp,mx] refcount=3, ntask=1, nconnector=1, nconn=1
debug: mta: scheduling relay [relay:127.0.0.1,port=10027,smtp,mx] in 1s...
imsg: lka <- pony: IMSG_GETNAMEINFO (len=28)
imsg: control <- queue: IMSG_STAT_INCREMENT (len=57)
ramstat: increment: queue.evpcache.load.hit
ramstat: queue.evpcache.load.hit (0x560e303b0e11): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=44)
ramstat: increment: mta.domain
ramstat: mta.domain (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=43)
ramstat: increment: mta.relay
ramstat: mta.relay (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=42)
ramstat: increment: mta.task
ramstat: mta.task (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=46)
ramstat: increment: mta.envelope
ramstat: mta.envelope (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=42)
ramstat: increment: mta.host
ramstat: mta.host (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=44)
ramstat: increment: mta.source
ramstat: mta.source (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=47)
ramstat: increment: mta.connector
ramstat: mta.connector (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=43)
ramstat: increment: mta.route
ramstat: mta.route (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=45)
ramstat: increment: mta.session
ramstat: mta.session (0x560e303ad0a1): 0 -> 1
mproc: lka -> pony : 22 IMSG_GETNAMEINFO
imsg: pony <- lka: IMSG_GETNAMEINFO (len=22)
4be49acee3232a85 mta connecting address=smtp://127.0.0.1:10027 host=localhost
mta: 0x5636709cf480: MTA_INIT -> MTA_INIT
mta: 0x5636709cf480: IO_CONNECTED <io:0x5636709d0680 fd=27 to=300000 fl=rw ib=0 ob=0>
4be49acee3232a85 mta connected
mta: 0x5636709cf480: MTA_INIT -> MTA_BANNER
smtp: 0x5636709c9570: connected to listener 0x563670a1fd10 [hostname=theos.kyriasis.com, port=10028, tag=from-dkimproxy-out]
mproc: pony -> lka : 28 IMSG_GETNAMEINFO
mproc: pony -> control : 46 IMSG_STAT_INCREMENT
mproc: pony -> control : 52 IMSG_STAT_INCREMENT
imsg: lka <- pony: IMSG_GETNAMEINFO (len=28)
imsg: control <- pony: IMSG_STAT_INCREMENT (len=46)
ramstat: increment: smtp.session
ramstat: smtp.session (0x560e303ad0a1): 0 -> 1
imsg: control <- pony: IMSG_STAT_INCREMENT (len=52)
ramstat: increment: smtp.session.inet4
ramstat: smtp.session.inet4 (0x560e303ad0a1): 0 -> 1
mproc: lka -> pony : 26 IMSG_GETNAMEINFO
imsg: pony <- lka: IMSG_GETNAMEINFO (len=26)
mproc: pony -> lka : 28 IMSG_GETADDRINFO
imsg: lka <- pony: IMSG_GETADDRINFO (len=28)
mproc: lka -> pony : 41 IMSG_GETADDRINFO
mproc: lka -> pony : 8 IMSG_GETADDRINFO_END
imsg: pony <- lka: IMSG_GETADDRINFO (len=41)
imsg: pony <- lka: IMSG_GETADDRINFO_END (len=8)
smtp: 0x5636709c9570: STATE_NEW -> STATE_CONNECTED
4be49acfc08e12e8 smtp connected address=127.0.0.1 host=localhost
mproc: pony -> lka : 96 IMSG_REPORT_SMTP_LINK_CONNECT
smtp: 0x5636709c9570: >>> 220 theos.kyriasis.com ESMTP OpenSMTPD
mproc: pony -> lka : 73 IMSG_REPORT_SMTP_PROTOCOL_SERVER
mproc: pony -> lka : 53 IMSG_??? (128)
smtp: 0x5636709c9570: IO_LOWAT <io:0x5636709cee30 fd=28 to=300000 fl=W ib=0 ob=0>
imsg: lka <- pony: IMSG_REPORT_SMTP_LINK_CONNECT (len=96)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=73)
imsg: lka <- pony: IMSG_??? (128) (len=53)
mta: 0x5636709cf480: IO_DATAIN <io:0x5636709d0680 fd=27 to=300000 fl=R ib=40 ob=0>
mta: 0x5636709cf480: <<< 220 theos.kyriasis.com ESMTP OpenSMTPD
mta: 0x5636709cf480: MTA_BANNER -> MTA_EHLO
mta: 0x5636709cf480: >>> EHLO theos.kyriasis.com
mta: 0x5636709cf480: IO_LOWAT <io:0x5636709d0680 fd=27 to=300000 fl=W ib=0 ob=0>
smtp: 0x5636709c9570: IO_DATAIN <io:0x5636709cee30 fd=28 to=300000 fl=R ib=25 ob=0>
smtp: 0x5636709c9570: <<< EHLO theos.kyriasis.com
mproc: pony -> lka : 58 IMSG_REPORT_SMTP_PROTOCOL_CLIENT
mproc: pony -> lka : 59 IMSG_??? (129)
smtp: 0x5636709c9570: STATE_CONNECTED -> STATE_HELO
smtp: 0x5636709c9570: >>> 250-theos.kyriasis.com Hello theos.kyriasis.com [127.0.0.1], pleased to meet you
mproc: pony -> lka : 115 IMSG_REPORT_SMTP_PROTOCOL_SERVER
smtp: 0x5636709c9570: >>> 250-8BITMIME
mproc: pony -> lka : 47 IMSG_REPORT_SMTP_PROTOCOL_SERVER
smtp: 0x5636709c9570: >>> 250-ENHANCEDSTATUSCODES
mproc: pony -> lka : 58 IMSG_REPORT_SMTP_PROTOCOL_SERVER
smtp: 0x5636709c9570: >>> 250-SIZE 36700160
mproc: pony -> lka : 52 IMSG_REPORT_SMTP_PROTOCOL_SERVER
smtp: 0x5636709c9570: >>> 250-DSN
mproc: pony -> lka : 42 IMSG_REPORT_SMTP_PROTOCOL_SERVER
smtp: 0x5636709c9570: >>> 250 HELP
mproc: pony -> lka : 43 IMSG_REPORT_SMTP_PROTOCOL_SERVER
smtp: 0x5636709c9570: IO_LOWAT <io:0x5636709cee30 fd=28 to=300000 fl=W ib=0 ob=0>
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_CLIENT (len=58)
imsg: lka <- pony: IMSG_??? (129) (len=59)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=115)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=47)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=58)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=52)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=42)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=43)
mta: 0x5636709cf480: IO_DATAIN <io:0x5636709d0680 fd=27 to=300000 fl=R ib=159 ob=0>
mta: 0x5636709cf480: <<< 250-theos.kyriasis.com Hello theos.kyriasis.com [127.0.0.1], pleased to meet you
mta: 0x5636709cf480: <<< 250-8BITMIME
mta: 0x5636709cf480: <<< 250-ENHANCEDSTATUSCODES
mta: 0x5636709cf480: <<< 250-SIZE 36700160
mta: 0x5636709cf480: <<< 250-DSN
mta: 0x5636709cf480: <<< 250 HELP
mta: 0x5636709cf480: MTA_EHLO -> MTA_STARTTLS
mta: 0x5636709cf480: MTA_STARTTLS -> MTA_AUTH
mta: 0x5636709cf480: MTA_AUTH -> MTA_READY
debug: mta-routing: route [] <-> 127.0.0.1 (localhost) is now valid.
debug: mta: connecting with [connector:[]->[relay:127.0.0.1,port=10027,smtp,mx],0x20000]
debug: mta: cancelling connector timeout
debug: mta: enough connections already
debug: mta: 0x5636709cf480: handling next task for relay [relay:127.0.0.1,port=10027,smtp,mx]
mproc: pony -> control : 50 IMSG_STAT_INCREMENT
mproc: pony -> queue: realloc 0 -> 128
mproc: pony -> queue : 12 IMSG_MTA_OPEN_MESSAGE
imsg: control <- pony: IMSG_STAT_INCREMENT (len=50)
ramstat: increment: mta.task.running
ramstat: mta.task.running (0x560e303ad0a1): 0 -> 1
imsg: queue <- pony: IMSG_MTA_OPEN_MESSAGE (len=12)
queue-backend: queue_message_fd_r(3a49b387) -> 11
mproc: queue -> pony : 8 IMSG_MTA_OPEN_MESSAGE
imsg: pony <- queue: IMSG_MTA_OPEN_MESSAGE (len=8, fd=29)
mta: 0x5636709cf480: MTA_READY -> MTA_MAIL
mta: 0x5636709cf480: >>> MAIL FROM:<[email protected]>
mta: 0x5636709cf480: IO_LOWAT <io:0x5636709d0680 fd=27 to=300000 fl=W ib=0 ob=0>
smtp: 0x5636709c9570: IO_DATAIN <io:0x5636709cee30 fd=28 to=300000 fl=R ib=30 ob=0>
smtp: 0x5636709c9570: <<< MAIL FROM:<[email protected]>
mproc: pony -> lka : 63 IMSG_REPORT_SMTP_PROTOCOL_CLIENT
mproc: pony -> queue : 8 IMSG_SMTP_MESSAGE_CREATE
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_CLIENT (len=63)
imsg: queue <- pony: IMSG_SMTP_MESSAGE_CREATE (len=8)
queue-backend: queue_message_create() -> 1 (dc578c1b)
mproc: queue -> pony : 16 IMSG_SMTP_MESSAGE_CREATE
imsg: pony <- queue: IMSG_SMTP_MESSAGE_CREATE (len=16)
mproc: pony -> lka : 37 IMSG_REPORT_SMTP_TX_BEGIN
smtp: 0x5636709c9570: >>> 250 2.0.0 Ok
mproc: pony -> lka : 59 IMSG_??? (134)
mproc: pony -> lka : 47 IMSG_REPORT_SMTP_PROTOCOL_SERVER
smtp: 0x5636709c9570: IO_LOWAT <io:0x5636709cee30 fd=28 to=300000 fl=W ib=0 ob=0>
mta: 0x5636709cf480: IO_DATAIN <io:0x5636709d0680 fd=27 to=300000 fl=R ib=14 ob=0>
mta: 0x5636709cf480: <<< 250 2.0.0 Ok
mta: 0x5636709cf480: MTA_MAIL -> MTA_RCPT
imsg: lka <- pony: IMSG_REPORT_SMTP_TX_BEGIN (len=37)
mta: 0x5636709cf480: >>> RCPT TO:<[email protected]>
imsg: lka <- pony: IMSG_??? (134) (len=59)
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=47)
mta: 0x5636709cf480: IO_LOWAT <io:0x5636709d0680 fd=27 to=300000 fl=W ib=0 ob=0>
smtp: 0x5636709c9570: IO_DATAIN <io:0x5636709cee30 fd=28 to=300000 fl=R ib=40 ob=0>
smtp: 0x5636709c9570: <<< RCPT TO:<[email protected]>
mproc: pony -> lka : 73 IMSG_REPORT_SMTP_PROTOCOL_CLIENT
mproc: pony -> lka: realloc 128 -> 512
mproc: pony -> lka : 291 IMSG_SMTP_EXPAND_RCPT
imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_CLIENT (len=73)
imsg: lka <- pony: IMSG_SMTP_EXPAND_RCPT (len=291)
expand: 0x563871371588: expand_insert() called for address:[email protected][parent=(nil), rule=(nil)]
expand: 0x563871371588: inserted node 0x563871373280
expand: lka_expand: address: [email protected] [depth=0]
lookup: match "from-dkimproxy-out" as STRING in table static:<dynamic:3> -> false
lookup: match "from-dkimproxy-out" as STRING in table static:<dynamic:4> -> false
lookup: match "from-dkimproxy-out" as STRING in table static:<dynamic:5> -> false
lookup: match "from-dkimproxy-out" as STRING in table static:<dynamic:6> -> false
lookup: match "from-dkimproxy-out" as STRING in table static:<dynamic:7> -> false
lookup: match "from-dkimproxy-out" as STRING in table static:<dynamic:8> -> false
debug: queue -> lookup: pipe closed
debug: queue agent exiting
debug: parent -> lka: pipe closed
smtpd: process lka socket closed
debug: pony -> lookup: pipe closed
debug: pony agent exiting
debug: ca -> parent: pipe closed
debug: ca agent exiting
debug: scheduler -> queue: pipe closed
debug: scheduler agent exiting
debug: control -> lookup: pipe closed
debug: control agent exiting
Raw
smtpd.conf
pki theos.kyriasis.com cert "/etc/smtpd/certs/fullchain.pem"
pki theos.kyriasis.com key "/etc/smtpd/certs/privkey.pem"
pki theos.kyriasis.com dhe auto
table allowed-senders file:/etc/smtpd/table-senders
table users file:/etc/smtpd/table-users
table backup-domains file:/etc/smtpd/table-domains-backup
table primary-domains file:/etc/smtpd/table-domains-primary
# incoming listeners
listen on eth0 port 25 tls pki theos.kyriasis.com tag from-external
listen on lo port 10026 tag from-dkimproxy-in
listen on lo port 10031 tag from-spampd
# outgoing listeners
listen on lo port 25 received-auth senders <allowed-senders> masquerade tag from-submission
listen on eth0 port 587 tls-require pki theos.kyriasis.com auth received-auth senders <allowed-senders> masquerade tag from-submission
listen on lo port 10028 tag from-dkimproxy-out
# incoming actions
action backup-relay relay backup mx theos.kyriasis.com
action to-dkimproxy-in relay host smtp://127.0.0.1:10025
action to-spampd relay host smtp://127.0.0.1:10030
action to-dovecot lmtp "/var/run/dovecot/lmtp" virtual <users>
# outgoing actions
action to-dkimproxy-out relay host smtp://127.0.0.1:10027
action "relay" relay
# incoming match rules
match from any for domain <backup-domains> tag from-external action backup-relay
match from any for domain <primary-domains> tag from-external action to-dkimproxy-in
match from any for any tag from-dkimproxy-in action to-spampd
match from any for domain <primary-domains> tag from-spampd action to-dovecot
match from any for any tag from-spampd action "relay"
# outgoing match rules
match from any for any tag from-submission action to-dkimproxy-out
match from socket for any action to-dkimproxy-out
match from any for any tag from-dkimproxy-out action "relay"
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment