logo       

dkim-filter and milter problem: msg#00090

mail.ims.general

Subject: dkim-filter and milter problem

Good day all, I have been trying to test signing messages with DKIM and libmilter. So far have had little luck. From the debug log below I see the mta interacting with the milter daemon but messages are not being signed. I am sure I'm missing something obvious. Technical and debug info below...

For the milter s/w I am using dkim-milter-2.3.2. Running on a different host with the following args: -l -p inet:8076 -d monkor.us -s monkor.localhost -k /var/opt/monkor.us.private -v

Those logs provide no real info...


Oct 27 16:27:35 monkor dkim-filter[29673]: 0JQL00G0L89XIA00 external host monkor.localhost attempted to send as monkor.us
Oct 27 16:34:17 monkor dkim-filter[29673]: 0JQL00G028L4K500 external host monkor.localhost attempted to send as monkor.us
Oct 27 16:42:15 monkor dkim-filter[29673]: 0JQL00G078YDK500 external host monkor attempted to send as monkor.us
Oct 27 16:43:09 monkor dkim-filter[29673]: 0JQL00G0A8ZVK500 external host monkor attempted to send as monkor.us



bash-2.05# imsimta version
Sun Java(tm) System Messaging Server 6.3-4.01 (built Aug 3 2007; 32bit)
libimta.so 6.3-4.01 (built 17:13:29, Aug 3 2007; 32bit)
SunOS homer 5.9 Generic_112233-03 sun4u sparc SUNW,Ultra-2

option.dat settings
spamfilter2_library=/opt/SUNWmsgsr/lib/libmilter.so
spamfilter2_config_file=/opt/SUNWmsgsr/config/milter.opt
spamfilter2_string_action=data:,$M

bash-2.05# more milter.opt
HOST=192.168.0.2
PORT=8076
DEBUG=2

imta.cnf opt-in setting

!
! tcp_intranet
tcp_intranet smtp mx single_sys subdirs 20 dequeue_removeroute maxjobs 2 pool SMTP_POOL maytlsserver allowswitchchannel saslswitchchanne
l tcp_auth missingrecipientpolicy 4 sourcespamfilter2optin spam
tcp_intranet-daemon

I have tried applying the same to tcp_local with the same lack of success. Is it possible the sourcespamfilterXoptin setting requires a different keyword?

Any help is appreciated
Thanks,
Anthony

16:59:55.81: Debug output enabled, program version V6.3 compiled Aug 3 2007 17:16:10
16:59:55.81: Sun Java(tm) System Messaging Server shared library version 6.3-4.01 linked 17:13:29, Aug 3 2007
16:59:55.81: SMTP server initiated on socket 6
16:59:55.81: Received connection from @[192.168.0.2]
16:59:55.82: Applying PORT_ACCESS mapping to "TCP|192.168.1.2|25|192.168.0.2|19661"
16:59:55.82: PORT_ACCESS result: EXTERNAL
16:59:55.82: Ruleset: EXTERNAL
16:59:55.82: Realm:
16:59:55.82: Sending : "220 homer -- Server ESMTP (Sun Java(tm) System Messaging Server 6.3-4.01 (built Aug 3 2007; 32bit))"
16:59:55.82: Received : "EHLO monkor"
16:59:55.82: Remote host IDENT information: [192.168.0.2]
16:59:55.82: Attempting channel switch: Rewriting "user@[192.168.0.2]"
16:59:55.82: Rewrite succeeded, matched channel tcp_intranet
16:59:55.82: Rewrite/switch succeeded, switched to channel: tcp_intranet
16:59:55.82: Sending : "250-homer"
16:59:55.82: Sending : "250-8BITMIME"
16:59:55.82: Sending : "250-PIPELINING"
16:59:55.82: Sending : "250-CHUNKING"
16:59:55.82: Sending : "250-DSN"
16:59:55.82: Sending : "250-ENHANCEDSTATUSCODES"
16:59:55.82: Sending : "250-EXPN"
16:59:55.82: Sending : "250-HELP"
16:59:55.82: Sending : "250-XADR"
16:59:55.82: Sending : "250-XSTA"
16:59:55.82: Sending : "250-XCIR"
16:59:55.82: Sending : "250-XGEN"
16:59:55.82: Sending : "250-XLOOP E232ADEE556BDF88401637C7428FEB1B"
16:59:55.82: Sending : "250-ETRN"
16:59:55.82: Sending : "250-NO-SOLICITING"
16:59:55.82: Sending : "250 SIZE 0"
16:59:55.83: Received : "MAIL
FROM:<apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx>"
16:59:55.83: Debug output enabled, system homer, process 53d5.7, message enqueue routines version V6.3 compiled Aug 3 2007 17:13:34
16:59:55.83:
mmc_winit('tcp_intranet','apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx','')
called.
16:59:55.83: mmc_determine_url beginning with pattern , xadr , mbox , domain , subaddress
16:59:55.83: Empty URL specified.
16:59:55.83: Address reversal invoked on apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx, force reverse URL 1, capture 1
16:59:55.83: mmc_address_to_tree: Parsing address.
16:59:55.83: Address: "apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx"
0x00000000
16:59:55.83: Right default: monko.net
16:59:55.83: Parsing address with null fixup.
16:59:55.83: mmc_address_to_tree: Returning.
16:59:55.83: Rewriting: Mbox = "apurcell", host = "monkor.us", domain = "$*", literal = "", tag = ""
16:59:55.83: Rewrite: "$*", position 0, hash table -
16:59:55.83: Found: "$A$E$F$U%$H$V$H@xxxxxxxxxxxxxxx"
16:59:55.83: Rewrite failed, not forward.
16:59:55.83: Rewrite: "$*", position 1, hash table -
16:59:55.83: Failed.
16:59:55.83: Rewrite: "$*", position 0, rewrite database -
16:59:55.83: Failed
16:59:55.83: Rewriting: Mbox = "apurcell", host = "monkor", domain = "monkor.us", literal = "", tag = ""
16:59:55.83: Rewrite: "monkor.us", position 0, hash table -
16:59:55.83: Failed.
16:59:55.83: Rewrite: "monkor.us", position 0, rewrite database -
16:59:55.83: Failed
16:59:55.83: Rewriting: Mbox = "apurcell", host = "monkor", domain = ".us", literal = "", tag = ""
16:59:55.83: Rewrite: "*.us", position 0, hash table -
16:59:55.83: Failed
16:59:55.83: Rewrite: ".us", position 0, hash table -
16:59:55.83: Found: "$U%$H$D@TCP-DAEMON"
16:59:55.83: New mailbox: "apurcell".
16:59:55.83: New host: "monkor.us".
16:59:55.84: New route: "TCP-DAEMON".
16:59:55.84: New channel system: "TCP-DAEMON".
16:59:55.84: Rewriting channel system TCP-DAEMON, current route TCP-DAEMON host monkor.us
16:59:55.84: Looking up host "TCP-DAEMON".
16:59:55.84: - found on channel tcp_local
16:59:55.84: Route1 result TCP-DAEMON route2 result TCP-DAEMON
16:59:55.84: Checking reverse URL cache for:
apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:55.84: Override postmaster:
postmaster-nHiPQxjAod9eoWH0uzbU5w@xxxxxxxxxxxxxxxx
16:59:55.84: Found in cache, result:
apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:55.84: Mapped return address:
apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:55.84: from_access mapping check: TCP|192.168.1.2|25|192.168.0.2|19661|SMTP/monkor|MAIL|tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|
16:59:55.84: Mapping 1 applied to TCP|192.168.1.2|25|192.168.0.2|19661|SMTP/monkor|MAIL|tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|
16:59:55.84: Entry #1 did not match, pattern "*|SMTP*|*|*|MAILER-DAEMON@*|*".
16:59:55.84: Entry #2 did not match, pattern "*|SMTP*|*|*|LISTSERVE*@|*".
16:59:55.84: Entry #3 did not match, pattern "*|SMTP*|*|*|majordomo@*|*".
16:59:55.84: Entry #4 did not match, pattern "*|SMTP*|*|*|*-request@*|*".
16:59:55.84: Entry #5 did not match, pattern "*|SMTP*|*|*|*-owner@*|*".
16:59:55.84: Entry #6 did not match, pattern "*|SMTP*|*|*|owner-*@*|*".
16:59:55.84: Final result "TCP|192.168.1.2|25|192.168.0.2|19661|SMTP/monkor|MAIL|tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|"
16:59:55.84: Queue area size 6353480, temp area size 158396
16:59:55.84: 1588370 blocks of effective free queue space available; setting disk limit accordingly.
16:59:55.84: 79198 blocks of free temporary space available; setting disk limit accordingly.
16:59:55.84: Initializing spam filter 1 message context
16:59:55.84: Initializing Milter message context
16:59:55.84: Creating socket to connect to milter server
16:59:55.84: Binding milter socket
16:59:55.84: Connecting to milter server IP #0
16:59:55.84: Sending Milter server the OPTNEG command length 13
16:59:55.84: send_milter_command: [10] sent 17 bytes
> 0000000D 4F000000 03000000 3F000000 ....O.......?...
> 7F
16:59:55.84: read_milter_response: [10] received 17 bytes
< 0000000D 4F000000 02000000 31000000 ....O.......1...
< 0A .
16:59:55.85: OPTNEG actions response = 49:
16:59:55.85: Add headers (SMFIR_ADDHEADER)
16:59:55.85: Change or delete headers (SMFIR_CHGHEADER)
16:59:55.85: Quarantine message (SMFIR_QUARANTINE)
16:59:55.85: OPTNEG protocol response = 10:
16:59:55.85: Skip HELO
16:59:55.85: Skip RCPT
16:59:55.85: Sending Milter server the MACRO command length 46
16:59:55.85: send_milter_command: [10] sent 50 bytes
> 0000002E 44436A00 686F6D65 722E6D6F ....DCj.homer.mo
> 6E6B6F2E 6E657400 7B636C69 656E745F nko.net.{client_
> 61646472 7D003139 322E3136 382E302E addr}.192.168.0.
> 3200 2.
16:59:55.85: Sending Milter server the CONNECT command length 23
16:59:55.85: send_milter_command: [10] sent 27 bytes
> 00000017 436D6F6E 6B6F7200 34001931 ....Cmonkor.4..1
> 39322E31 36382E30 2E3200 92.168.0.2.
16:59:55.89: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:55.89: Received milter response 'c'
16:59:55.89: Processing continues...
16:59:55.89: Skipping milter HELO
16:59:55.89: Sending Milter server the MACRO command length 104
16:59:55.89: send_milter_command: [10] sent 108 bytes
> 00000068 444D6900 304A514C 30304730 ...hDMi.0JQL00G0
> 41385A56 4B353030 007B6D61 696C5F61 A8ZVK500.{mail_a
> 6464727D 00617075 7263656C 6C406D6F ddr}.apurcell@mo
> 6E6B6F72 2E757300 7B6D6169 6C5F686F nkor.us.{mail_ho
> 73747D00 6D6F6E6B 6F722E75 73007B73 st}.monkor.us.{s
> 6F757263 655F6368 616E6E65 6C7D0074 ource_channel}.t
> 63705F69 6E747261 6E657400 cp_intranet.
16:59:55.89: Sending Milter server the MAIL command length 22
16:59:55.89: send_milter_command: [10] sent 26 bytes
> 00000016 4D3C6170 75726365 6C6C406D ....M<apurcell@m
> 6F6E6B6F 722E7573 3E00 onkor.us>.
16:59:55.95: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:55.95: Received milter response 'c'
16:59:55.95: Processing continues...
16:59:55.95: - passed.
16:59:55.95: mmc_address_to_tree: Parsing address.
16:59:55.95: Address: "apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx"
0x00000000
16:59:55.95: Right default: monko.net
16:59:55.95: Parsing address with local fixup.
16:59:55.95: mmc_address_to_tree: Returning.
16:59:55.95: Rewriting: Mbox = "apurcell", host = "monkor.us", domain = "$*", literal = "", tag = ""
16:59:55.95: Rewrite: "$*", position 0, hash table -
16:59:55.95: Found: "$A$E$F$U%$H$V$H@xxxxxxxxxxxxxxx"
16:59:55.95: Rewrite failed, not forward.
16:59:55.95: Rewrite: "$*", position 1, hash table -
16:59:55.95: Failed.
16:59:55.95: Rewrite: "$*", position 0, rewrite database -
16:59:55.95: Failed
16:59:55.95: Rewriting: Mbox = "apurcell", host = "monkor", domain = "monkor.us", literal = "", tag = ""
16:59:55.95: Rewrite: "monkor.us", position 0, hash table -
16:59:55.95: Failed.
16:59:55.95: Rewrite: "monkor.us", position 0, rewrite database -
16:59:55.95: Failed
16:59:55.95: Rewriting: Mbox = "apurcell", host = "monkor", domain = ".us", literal = "", tag = ""
16:59:55.95: Rewrite: "*.us", position 0, hash table -
16:59:55.95: Failed
16:59:55.95: Rewrite: ".us", position 0, hash table -
16:59:55.95: Found: "$U%$H$D@TCP-DAEMON"
16:59:55.95: New mailbox: "apurcell".
16:59:55.95: New host: "monkor.us".
16:59:55.95: New route: "TCP-DAEMON".
16:59:55.95: New channel system: "TCP-DAEMON".
16:59:55.95: Rewriting channel system TCP-DAEMON, current route TCP-DAEMON host monkor.us
16:59:55.95: Looking up host "TCP-DAEMON".
16:59:55.95: - found on channel tcp_local
16:59:55.95: Route1 result TCP-DAEMON route2 result TCP-DAEMON
16:59:55.95: mmc_rrply: Return detailed status information.
16:59:55.95: mmc_rrply: Returning return address and channel OK
16:59:55.95: Sending : "250 2.5.0 Address Ok."
16:59:55.96: Received : "RCPT TO:<apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx>"
16:59:55.96: mmc_wadr(0x00396120,'','apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx')
called.
16:59:55.96: Copy estimate before address addition is 1
16:59:55.96: Parsing address apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.96: mmc_address_to_tree: Parsing address.
16:59:55.96: Address: "apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx" 0x00000000
16:59:55.96: Right default: monko.net
16:59:55.96: Parsing address with local fixup.
16:59:55.96: mmc_address_to_tree: Returning.
16:59:55.96: Rewriting: Mbox = "apurcell", host = "cv.net", domain = "$*", literal = "", tag = ""
16:59:55.96: Rewrite: "$*", position 0, hash table -
16:59:55.96: Found: "$A$E$F$U%$H$V$H@xxxxxxxxxxxxxxx"
16:59:55.96: Match, pattern = "cv.net", current = "(*domaincheck*)"
16:59:55.96: old state = not checked.
16:59:55.96: Using result 0 from domain match cache.
16:59:55.96: new state = fail pending.
16:59:55.96: Rewrite failed due to prechannel mismatch.
16:59:55.96: Rewrite: "$*", position 1, hash table -
16:59:55.96: Failed.
16:59:55.96: Rewrite: "$*", position 0, rewrite database -
16:59:55.96: Failed
16:59:55.96: Rewriting: Mbox = "apurcell", host = "cv", domain = "cv.net", literal = "", tag = ""
16:59:55.96: Rewrite: "cv.net", position 0, hash table -
16:59:55.96: Failed.
16:59:55.96: Rewrite: "cv.net", position 0, rewrite database -
16:59:55.96: Failed
16:59:55.96: Rewriting: Mbox = "apurcell", host = "cv", domain = ".net", literal = "", tag = ""
16:59:55.96: Rewrite: "*.net", position 0, hash table -
16:59:55.96: Failed
16:59:55.96: Rewrite: ".net", position 0, hash table -
16:59:55.96: Found: "$U%$H$D@TCP-DAEMON"
16:59:55.96: New mailbox: "apurcell".
16:59:55.96: New host: "cv.net".
16:59:55.96: New route: "TCP-DAEMON".
16:59:55.96: New channel system: "TCP-DAEMON".
16:59:55.96: Rewriting channel system TCP-DAEMON, current route TCP-DAEMON host cv.net
16:59:55.96: Looking up host "TCP-DAEMON".
16:59:55.96: - found on channel tcp_local
16:59:55.96: Route1 result TCP-DAEMON route2 result TCP-DAEMON
16:59:55.96: - adding address apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx to
headers.
16:59:55.96: - orig_send_access mapping check: tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.96: Mapping 4 applied to tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.96: Entry #1 did not match, pattern "tcp_local|*|tcp_local|*".
16:59:55.96: Entry #2 did not match, pattern "tcp_*|*|native|*".
16:59:55.96: Entry #3 did not match, pattern "tcp_*|*|hold|*".
16:59:55.96: Entry #4 did not match, pattern "tcp_*|*|pipe|*".
16:59:55.96: Entry #5 did not match, pattern "tcp_*|*|ims-ms|*".
16:59:55.97: Entry #6 did not match, pattern "tcp_local|*|tcp_intranet|@*:*.*".
16:59:55.97: Entry #7 did not match, pattern "tcp_local|*|tcp_intranet|*$%*@*".
16:59:55.97: Entry #8 did not match, pattern "tcp_local|*|tcp_intranet|*.*!*@*".
16:59:55.97: Entry #9 did not match, pattern "tcp_local|*|tcp_intranet|"*@*"@*".
16:59:55.97: Final result "tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx"
16:59:55.97: - passed.
16:59:55.97: - send_access mapping check: tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.97: Mapping 6 applied to tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.97: Entry #1 did not match, pattern "tcp_*|*|*|*@[127.*]".
16:59:55.97: Entry #2 did not match, pattern "tcp_*|*.tw|*|*.tw".
16:59:55.97: Entry #3 did not match, pattern "tcp_*|*@gmail.com|*|*@gmail.com".
16:59:55.97: Entry #4 did not match, pattern "tcp_*|*|*|*@example.com".
16:59:55.97: Entry #5 did not match, pattern "tcp_*|*|*|*@example.net".
16:59:55.97: Entry #6 did not match, pattern "tcp_*|*|*|*@example.org".
16:59:55.97: Entry #7 did not match, pattern "tcp_*|*@example.org|*|*".
16:59:55.97: Entry #8 did not match, pattern "tcp_*|*|*|*@*.example".
16:59:55.97: Entry #9 did not match, pattern "tcp_*|*|*|*@*.invalid".
16:59:55.97: Entry #10 did not match, pattern "tcp_*|*|*|*@*.localhost".
16:59:55.97: Final result "tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx"
16:59:55.97: - passed.
16:59:55.97: - orig_mail_access mapping check: TCP|192.168.1.2|25|192.168.0.2|19661|SMTP/monkor|MAIL|tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell@
cv.net
16:59:55.97: Mapping 5 applied to TCP|192.168.1.2|25|192.168.0.2|19661|SMTP/monkor|MAIL|tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.97: Final result "TCP|192.168.1.2|25|192.168.0.2|19661|SMTP/monkor|MAIL|tcp_intranet|apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx|tcp_local|apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx"
16:59:55.97: - passed.
16:59:55.97: - Spam filter 0 not disabled, checking this recipient
16:59:55.97: - Spam filter 1 not disabled, checking this recipient
16:59:55.97: - Spam filter optin = spam
16:59:55.97: - Submitting address apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
to spam filter
16:59:55.97: Milter recipient: apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.97: Skipping milter RCPT
16:59:55.97: - Spam filter 2 not disabled, checking this recipient
16:59:55.97: - Spam filter 3 not disabled, checking this recipient
16:59:55.97: - Spam filter 4 not disabled, checking this recipient
16:59:55.97: - Spam filter 5 not disabled, checking this recipient
16:59:55.97: - Spam filter 6 not disabled, checking this recipient
16:59:55.97: - Spam filter 7 not disabled, checking this recipient
16:59:55.97: - adding address apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx to channel tcp_local
16:59:55.97: - Copy estimate now 2
16:59:55.97: - Storing address apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx in spam filter hash table at index 781
16:59:55.97: Good address count 1 defer count 0
16:59:55.97: Copy estimate after address addition is 2
16:59:55.97: mmc_rrply: Return detailed status information.
16:59:55.97: mmc_rrply: Returning
16:59:55.97: Sending : "250 2.1.5 apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx OK."
16:59:55.98: Received : "DATA"
16:59:55.98: mmc_waend(0x00396120) called.
16:59:55.98: Copy estimate is 2
16:59:55.98: Milter end to list, start header
16:59:55.98: Queue area size 6353464, temp area size 158360
16:59:55.98: 1588366 blocks of effective free queue space available; setting disk limit accordingly.
16:59:55.98: 79180 blocks of free temporary space available; setting disk limit accordingly.
16:59:55.98: Sending : "354 Enter mail, end with a single "."."
16:59:55.98: mmc_output_line(0x00396120) header line: Received: from [127.0.0.1]
16:59:55.98: Sending Milter server the HEADER command length 107
16:59:55.98: send_milter_command: [10] sent 111 bytes
> 0000006B 4C526563 65697665 64006672 ...kLReceived.fr
> 6F6D206D 6F6E6B6F 7220285B 3139322E om monkor ([192.
> 3136382E 302E325D 29206279 20686F6D 168.0.2]) by hom
> 65722E6D 6F6E6B6F 2E6E6574 20776974 er.monko.net wit
> 68204553 4D54503B 20536174 2C203237 h ESMTP; Sat, 27
> 204F6374 20323030 37203136 3A35393A Oct 2007 16:59:
> 3535202D 30343030 20284544 542900 55 -0400 (EDT).
16:59:55.99: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:55.99: Received milter response 'c'
16:59:55.99: Processing continues...
16:59:55.99: mmc_output_line(0x00396120) header line: by localhost with HTTP; Sat, 27 Oct 2007 16:43:08 -0400
16:59:55.99: mmc_output_line(0x00396120) header line: Date: Sat, 27 Oct 2007 16:43:08 -0400 (EDT)
16:59:55.99: Sending Milter server the HEADER command length 83
16:59:55.99: send_milter_command: [10] sent 87 bytes
> 00000053 4C526563 65697665 64006672 ...SLReceived.fr
> 6F6D205B 3132372E 302E302E 315D0962 om [127.0.0.1].b
> 79206C6F 63616C68 6F737420 77697468 y localhost with
> 20485454 503B2053 61742C20 3237204F HTTP; Sat, 27 O
> 63742032 30303720 31363A34 333A3038 ct 2007 16:43:08
> 202D3034 303000 -0400.
16:59:55.99: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:55.99: Received milter response 'c'
16:59:55.99: Processing continues...
16:59:55.99: mmc_output_line(0x00396120) header line: From: Anthony <apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx>
16:59:55.99: Sending Milter server the HEADER command length 44
16:59:55.99: send_milter_command: [10] sent 48 bytes
> 0000002C 4C446174 65005361 742C2032 ...,LDate.Sat, 2
> 37204F63 74203230 30372031 363A3433 7 Oct 2007 16:43
> 3A303820 2D303430 30202845 44542900 :08 -0400 (EDT).
16:59:55.99: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:55.99: Received milter response 'c'
16:59:55.99: Processing continues...
16:59:55.99: mmc_output_line(0x00396120) header line: To:
apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:55.99: Sending Milter server the HEADER command length 35
16:59:55.99: send_milter_command: [10] sent 39 bytes
> 00000023 4C46726F 6D00416E 74686F6E ...#LFrom.Anthon
> 79203C61 70757263 656C6C40 6D6F6E6B y <apurcell@monk
> 6F722E75 733E00 or.us>.
16:59:55.99: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:55.99: Received milter response 'c'
16:59:55.99: Processing continues...
16:59:55.99: mmc_output_line(0x00396120) header line: Message-ID: <14963515.31193517788913.JavaMail.apurcell-Q0ErXNX1RuZFm8j7Q0jE0A@xxxxxxxxxxxxxxxx>
16:59:55.99: Sending Milter server the HEADER command length 20
16:59:55.99: send_milter_command: [10] sent 24 bytes
> 00000014 4C546F00 61707572 63656C6C ....LTo.apurcell
> 4063762E 6E657400 @cv.net.
16:59:56.00: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.00: Received milter response 'c'
16:59:56.00: Processing continues...
16:59:56.00: mmc_output_line(0x00396120) header line: Subject: test
16:59:56.00: Sending Milter server the HEADER command length 69
16:59:56.00: send_milter_command: [10] sent 73 bytes
> 00000045 4C4D6573 73616765 2D494400 ...ELMessage-ID.
> 3C313439 36333531 352E3331 31393335 <14963515.311935
> 31373738 38393133 2E4A6176 614D6169 17788913.JavaMai
> 6C2E6170 75726365 6C6C4031 39322E31 l.apurcell@xxxxx
> 36382E30 2E32353E 00 68.0.25>.
16:59:56.00: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.00: Received milter response 'c'
16:59:56.00: Processing continues...
16:59:56.00: mmc_output_line(0x00396120) header line: MIME-Version: 1.0
16:59:56.00: Sending Milter server the HEADER command length 14
16:59:56.00: send_milter_command: [10] sent 18 bytes
> 0000000E 4C537562 6A656374 00746573 ....LSubject.tes
> 7400 t.
16:59:56.00: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.00: Received milter response 'c'
16:59:56.00: Processing continues...
16:59:56.00: mmc_output_line(0x00396120) header line: Content-Type: text/plain; charset=UTF-8; format=flowed; delsp=no
16:59:56.00: Sending Milter server the HEADER command length 18
16:59:56.00: send_milter_command: [10] sent 22 bytes
> 00000012 4C4D494D 452D5665 7273696F ....LMIME-Versio
> 6E00312E 3000 n.1.0.
16:59:56.00: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.00: Received milter response 'c'
16:59:56.00: Processing continues...
16:59:56.00: mmc_output_line(0x00396120) header line: Content-Transfer-Encoding: 7bit
16:59:56.00: Sending Milter server the HEADER command length 65
16:59:56.00: send_milter_command: [10] sent 69 bytes
> 00000041 4C436F6E 74656E74 2D547970 ...ALContent-Typ
> 65007465 78742F70 6C61696E 3B206368 e.text/plain; ch
> 61727365 743D5554 462D383B 20666F72 arset=UTF-8; for
> 6D61743D 666C6F77 65643B20 64656C73 mat=flowed; dels
> 703D6E6F 00 p=no.
16:59:56.01: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.01: Received milter response 'c'
16:59:56.01: Processing continues...
16:59:56.01: mmc_output_line(0x00396120) header line: User-Agent: Laszlo Mail 2
16:59:56.01: Sending Milter server the HEADER command length 32
16:59:56.01: send_milter_command: [10] sent 36 bytes
> 00000020 4C436F6E 74656E74 2D547261 ... LContent-Tra
> 6E736665 722D456E 636F6469 6E670037 nsfer-Encoding.7
> 62697400 bit.
16:59:56.01: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.01: Received milter response 'c'
16:59:56.01: Processing continues...
16:59:56.01: mmc_output_line(0x00396120) header line: X-Originating-IP: [127.0.0.1]
16:59:56.01: Sending Milter server the HEADER command length 26
16:59:56.01: send_milter_command: [10] sent 30 bytes
> 0000001A 4C557365 722D4167 656E7400 ....LUser-Agent.
> 4C61737A 6C6F204D 61696C20 3200 Laszlo Mail 2.
16:59:56.01: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.01: Received milter response 'c'
16:59:56.01: Processing continues...
16:59:56.01: mmc_output_line(0x00396120) header line: Content-Disposition: inline
16:59:56.01: Sending Milter server the HEADER command length 30
16:59:56.01: send_milter_command: [10] sent 34 bytes
> 0000001E 4C582D4F 72696769 6E617469 ....LX-Originati
> 6E672D49 50005B31 32372E30 2E302E31 ng-IP.[127.0.0.1
> 5D00 ].
16:59:56.01: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.01: Received milter response 'c'
16:59:56.01: Processing continues...
16:59:56.01: mmc_fixup_header: Fixing up primary header.
16:59:56.01: Milter plugin end header called
16:59:56.02: Sending Milter server the HEADER command length 28
16:59:56.02: send_milter_command: [10] sent 32 bytes
> 0000001C 4C436F6E 74656E74 2D446973 ....LContent-Dis
> 706F7369 74696F6E 00696E6C 696E6500 position.inline.
16:59:56.02: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.02: Received milter response 'c'
16:59:56.02: Processing continues...
16:59:56.02: Sending Milter server the EOH command length 1
16:59:56.02: send_milter_command: [10] sent 5 bytes
> 00000001 4E ....N
16:59:56.02: read_milter_response: [10] received 5 bytes
< 00000001 63 ....c
16:59:56.02: Received milter response 'c'
16:59:56.02: Processing continues...
16:59:56.02: Removing Content-Length, Status, X-UID, and Original-Recipient fields
16:59:56.02: Received : ... 14 line(s) 481 byte(s) message body...
16:59:56.02: Checking for prior message file 'IMTA_QUEUE:tcp_intranet/spool/92FA406382354D0B7EB6FA193799BEAB.data-failed'
16:59:56.02: mmc_wtend(0x00396120) called.
16:59:56.02: Milter plugin end body called
16:59:56.02: Sending Milter server the BODYEOB command length 1
16:59:56.02: send_milter_command: [10] sent 5 bytes
> 00000001 45 ....E
16:59:56.02: Checking size limits.
16:59:56.02: Rough message size is 1
16:59:56.02: Message size is OK
16:59:56.02: Milter plugin end message called
16:59:56.03: read_milter_response: [10] received 5 bytes
< 00000001 61 ....a
16:59:56.03: Received milter response 'a'
16:59:56.03: Accepting message without further processing
16:59:56.03: Closing connection after accept
16:59:56.03: Sending Milter server the QUIT command length 1
16:59:56.03: send_milter_command: [10] sent 5 bytes
> 00000001 51 ....Q
16:59:56.03: Scan verdict #1, status = 0
16:59:56.03: Scan verdict: Deliver normally.
16:59:56.03: Generating boundary marker
16:59:56.03: Boundary marker Boundary_(ID_xlra7Dl0LP8GMqmhL3zX8A) generated
16:59:56.03: Using default 7bit charset ""
16:59:56.03: Processing any active filters.
16:59:56.03: Set up for logging.
16:59:56.03: mmc_flatten_address: Flattening address tree into a list.
16:59:56.03: Addresses found on channel tcp_local
16:59:56.03: Message priority value determined to be: 3
16:59:56.03: Checking sieve results for this channel's addresses.
16:59:56.03: Conversion mapping probe: IN-CHAN=tcp_intranet;OUT-CHAN=tcp_local;CONVERT
16:59:56.03: Mapping 7 applied to IN-CHAN=tcp_intranet;OUT-CHAN=tcp_local;CONVERT
16:59:56.03: Entry #1 matched, pattern "IN-CHAN=*;OUT-CHAN=*;CONVERT", template "Yes", match #0.
16:59:56.03: New target "Yes"
16:59:56.03: Exiting...
16:59:56.03: Final result "Yes"
16:59:56.03: Probe matched and enabled conversion.
16:59:56.03: Conversion enabled; charset conversion disabled.
16:59:56.03: Message priority value recomputed to be: 3
16:59:56.04: mmc_open_line: Opening /opt/SUNWmsgsr/data/queue/conversion/ZZf0M5c0AdNj2.00
, block estimate 1.
16:59:56.04: Translated filename: /opt/SUNWmsgsr/data/queue/conversion/ZZf0M5c0AdNj2.00
16:59:56.05: File opened
16:59:56.05: Message file /opt/SUNWmsgsr/data/queue/conversion/ZZf0M5c0AdNj2.00 created.
16:59:56.05: Message time = Sat, 27 Oct 2007 16:59:56 -0400 (EDT)
16:59:56.05: Message time = 1193518796
16:59:56.05: Message priority = 3
16:59:56.05: Address reversal invoked on apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx, force reverse URL 0, capture 0
16:59:56.05: mmc_address_to_tree: Parsing address.
16:59:56.05: Address: "apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx"
0x00000000
16:59:56.05: Right default: monko.net
16:59:56.05: Parsing address with null fixup.
16:59:56.05: mmc_address_to_tree: Returning.
16:59:56.05: Rewriting: Mbox = "apurcell", host = "monkor.us", domain = "$*", literal = "", tag = ""
16:59:56.05: Rewrite: "$*", position 0, hash table -
16:59:56.05: Found: "$A$E$F$U%$H$V$H@xxxxxxxxxxxxxxx"
16:59:56.05: Rewrite failed, not forward.
16:59:56.05: Rewrite: "$*", position 1, hash table -
16:59:56.05: Failed.
16:59:56.05: Rewrite: "$*", position 0, rewrite database -
16:59:56.05: Failed
16:59:56.05: Rewriting: Mbox = "apurcell", host = "monkor", domain = "monkor.us", literal = "", tag = ""
16:59:56.05: Rewrite: "monkor.us", position 0, hash table -
16:59:56.05: Failed.
16:59:56.05: Rewrite: "monkor.us", position 0, rewrite database -
16:59:56.05: Failed
16:59:56.05: Rewriting: Mbox = "apurcell", host = "monkor", domain = ".us", literal = "", tag = ""
16:59:56.05: Rewrite: "*.us", position 0, hash table -
16:59:56.05: Failed
16:59:56.05: Rewrite: ".us", position 0, hash table -
16:59:56.05: Found: "$U%$H$D@TCP-DAEMON"
16:59:56.05: New mailbox: "apurcell".
16:59:56.05: New host: "monkor.us".
16:59:56.05: New route: "TCP-DAEMON".
16:59:56.05: New channel system: "TCP-DAEMON".
16:59:56.05: Rewriting channel system TCP-DAEMON, current route TCP-DAEMON host monkor.us
16:59:56.05: Looking up host "TCP-DAEMON".
16:59:56.05: - found on channel tcp_local
16:59:56.05: Route1 result TCP-DAEMON route2 result TCP-DAEMON
16:59:56.05: Checking reverse URL cache for:
apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:56.05: Found in cache, result:
apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:56.06: Envelope from: apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:56.06: Original address type: rfc822
16:59:56.06: Original address: apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:56.06: Current address: apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:56.06: Creating log entry.
16:59:56.06: Address list exhausted.
16:59:56.06: End of envelope.
16:59:56.06: Building header instance.
16:59:56.06: Header copied.
16:59:56.06: mmc_rewrite_header: Rewriting header.
16:59:56.06: Content-disposition: header field(s) found.
16:59:56.06: Content disposition: inline
16:59:56.06: Start of new content disposition field: inline
16:59:56.06: Content-transfer-encoding: header field(s) found.
16:59:56.06: Content-type: header field(s) found.
16:59:56.06: Content type: text
16:59:56.06: Content subtype: plain
16:59:56.06: Content type parameters:
charset=UTF-8
format=flowed
delsp=no
16:59:56.06: Start of new content type field: text/plain; charset=UTF-8; format=flowed; delsp=no
16:59:56.06: Date: header field(s) found.
16:59:56.06: From: header field(s) found.
16:59:56.06: mmc_sender_rewrite: Rewriting header line.
16:59:56.06: mmc_address_to_tree: Parsing address.
16:59:56.06: Address: "Anthony
<apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx>" 0x00000000
16:59:56.06: Right default: monko.net
16:59:56.06: Parsing address with null fixup.
16:59:56.06: mmc_address_to_tree: Returning.
16:59:56.06: Parse successful.
16:59:56.06: Rewriting: Mbox = "apurcell", host = "monkor.us", domain = "$*", literal = "", tag = ""
16:59:56.06: Rewrite: "$*", position 0, hash table -
16:59:56.06: Found: "$A$E$F$U%$H$V$H@xxxxxxxxxxxxxxx"
16:59:56.06: Rewrite failed, not envelope.
16:59:56.06: Rewrite: "$*", position 1, hash table -
16:59:56.06: Failed.
16:59:56.06: Rewrite: "$*", position 0, rewrite database -
16:59:56.06: Failed
16:59:56.06: Rewriting: Mbox = "apurcell", host = "monkor", domain = "monkor.us", literal = "", tag = ""
16:59:56.06: Rewrite: "monkor.us", position 0, hash table -
16:59:56.06: Failed.
16:59:56.06: Rewrite: "monkor.us", position 0, rewrite database -
16:59:56.06: Failed
16:59:56.06: Rewriting: Mbox = "apurcell", host = "monkor", domain = ".us", literal = "", tag = ""
16:59:56.07: Rewrite: "*.us", position 0, hash table -
16:59:56.07: Failed
16:59:56.07: Rewrite: ".us", position 0, hash table -
16:59:56.07: Found: "$U%$H$D@TCP-DAEMON"
16:59:56.07: New mailbox: "apurcell".
16:59:56.07: New host: "monkor.us".
16:59:56.07: New route: "TCP-DAEMON".
16:59:56.07: New channel system: "TCP-DAEMON".
16:59:56.07: Rewriting channel system TCP-DAEMON, current route TCP-DAEMON host monkor.us
16:59:56.07: Looking up host "TCP-DAEMON".
16:59:56.07: - found on channel tcp_local
16:59:56.07: Route1 result TCP-DAEMON route2 result TCP-DAEMON
16:59:56.07: Rewrite rules result:
apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:56.07: Checking reverse URL cache for:
apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx
16:59:56.07: Found in cache, result:
<apurcell-lcpFe1T8Jdv1P9xLtpHBDw@xxxxxxxxxxxxxxxx>
16:59:56.07: mmc_sender_rewrite: Returning.
16:59:56.07: Message-id: header field(s) found.
16:59:56.07: mmc_sender_rewrite: Rewriting header line.
16:59:56.07: mmc_address_to_tree: Parsing address.
16:59:56.07: Address: "<14963515.31193517788913.JavaMail.apurcell-Q0ErXNX1RuZFm8j7Q0jE0A@xxxxxxxxxxxxxxxx>" 0x00000000
16:59:56.07: Right default: monko.net
16:59:56.07: Parsing address with null fixup.
16:59:56.07: mmc_address_to_tree: Returning.
16:59:56.07: Parse successful.
16:59:56.07: Repaired result: 14963515.31193517788913.JavaMail.apurcell-Q0ErXNX1RuZFm8j7Q0jE0A@xxxxxxxxxxxxxxxx
16:59:56.07: mmc_sender_rewrite: Returning.
16:59:56.07: MIME-version: header field(s) found.
16:59:56.07: Received: header field(s) found.
16:59:56.07: Subject: header field(s) found.
16:59:56.07: To: header field(s) found.
16:59:56.07: mmc_sender_rewrite: Rewriting header line.
16:59:56.07: mmc_address_to_tree: Parsing address.
16:59:56.07: Address: "apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx" 0x00000000
16:59:56.07: Right default: monko.net
16:59:56.07: Parsing address with null fixup.
16:59:56.07: mmc_address_to_tree: Returning.
16:59:56.07: Parse successful.
16:59:56.07: Rewriting: Mbox = "apurcell", host = "cv.net", domain = "$*", literal = "", tag = ""
16:59:56.07: Rewrite: "$*", position 0, hash table -
16:59:56.07: Found: "$A$E$F$U%$H$V$H@xxxxxxxxxxxxxxx"
16:59:56.07: Rewrite failed, not envelope.
16:59:56.07: Rewrite: "$*", position 1, hash table -
16:59:56.07: Failed.
16:59:56.07: Rewrite: "$*", position 0, rewrite database -
16:59:56.07: Failed
16:59:56.08: Rewriting: Mbox = "apurcell", host = "cv", domain = "cv.net", literal = "", tag = ""
16:59:56.08: Rewrite: "cv.net", position 0, hash table -
16:59:56.08: Failed.
16:59:56.08: Rewrite: "cv.net", position 0, rewrite database -
16:59:56.08: Failed
16:59:56.08: Rewriting: Mbox = "apurcell", host = "cv", domain = ".net", literal = "", tag = ""
16:59:56.08: Rewrite: "*.net", position 0, hash table -
16:59:56.08: Failed
16:59:56.08: Rewrite: ".net", position 0, hash table -
16:59:56.08: Found: "$U%$H$D@TCP-DAEMON"
16:59:56.08: New mailbox: "apurcell".
16:59:56.08: New host: "cv.net".
16:59:56.08: New route: "TCP-DAEMON".
16:59:56.08: New channel system: "TCP-DAEMON".
16:59:56.08: Rewriting channel system TCP-DAEMON, current route TCP-DAEMON host cv.net
16:59:56.08: Looking up host "TCP-DAEMON".
16:59:56.08: - found on channel tcp_local
16:59:56.08: Route1 result TCP-DAEMON route2 result TCP-DAEMON
16:59:56.08: Rewrite rules result: apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:56.08: Checking reverse URL cache for:
apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:56.08: Applying reverse URL pattern ldap:///$V?$N?sub?$R to: apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx
16:59:56.08: mmc_determine_url beginning with pattern ldap:///$V?$N?sub?$R, xadr apurcell-riaM9zG6NhA@xxxxxxxxxxxxxxxx, mbox , domain , subaddress
16:59:56.08: Nonpositive entry 0 in domain match cache.
16:59:56.08: URL generation failed, status = 0
16:59:56.08: mmc_sender_rewrite: Returning.
16:59:56.08: User-Agent: header field(s) found.
16:59:56.08: X-Originating-IP: header field(s) found.
16:59:56.08: mmc_rewrite_header: Rewriting complete.
16:59:56.08: Header instance built.
16:59:56.08: Checking split limit.
16:59:56.08: Writing header.
16:59:56.08: Writing message body.
16:59:56.08: Terminating message body.
16:59:56.08: Closing message file.
16:59:56.09: Creating queue cache entry.
16:59:56.13: Primary channel entries completed.
16:59:56.13: Freeing Milter message context
16:59:56.13: mmc_wtend: returning.
16:59:56.13: mmc_rrply: Return detailed status information.
16:59:56.13: mmc_rrply: Returning submitted
16:59:56.13: Sending : "250 2.5.0 Ok."
16:59:56.13: Received : "QUIT"
16:59:56.13: Sending : "221 2.3.0 Bye received. Goodbye."
16:59:56.13: smtpc_enqueue returning a status of 9 (OK)
16:59:56.13: pmt_close: [6] status 0



<Prev in Thread] Current Thread [Next in Thread>
Google Custom Search

News | FAQ | advertise