procmailrc not forwarding mail

10 posts / 0 new
Last post
#1 Tue, 06/15/2010 - 07:36
danhole

procmailrc not forwarding mail

I have an issue with procmailrc not forwarding my messages, if i set this up for a user by logging into usermin then creating their forward or manually creating the procmailrc file in their maildir

to confuse the situation even more if i create a brand new user and follow the same steps it works no problem ?????

I want to set it up this way so that the email is forwarded after it has been spam checked. the users main domain is setup on here then it is forwarding certain users to an exchange server.

here is my procmailrc file

VERBOSE=YES
LOGABSTRACT=YES
:0c
! first.last@domain.local

here is my procmail.log

procmail: Assigning "LOGABSTRACT=YES"
procmail: Executing "/usr/sbin/sendmail,-oi,first.last@domain.local"
procmail: Assigning "LASTFOLDER=/usr/sbin/sendmail -oi first.last@domain.local"
procmail: Assigning "LASTFOLDER=/home/domain.com/homes/first.last/Maildir/new/1276605212.27008_0.mail.domain.com"
procmail: Notified comsat: "first.last-domain.com@0:/home/domain.com/homes/first.last/Maildir/new/1276605212.27008_0.mail.domain.com"
From first.last@senderdomain.com  Tue Jun 15 13:33:31 2010
 Subject: test to dan
  Folder: /home/domain.com/homes/first.last/Maildir/new/1276605212    38454
Tue, 06/15/2010 - 09:13
andreychek

Can you verify a few things with that procmailrc file? Some things to check are --

  1. That it's named .procmailrc

  2. It's located in your users home directory

  3. That the permissions are something like "644", and that it's owned by your user and not someone else.

From your log above, it doesn't look like your .procmailrc is being hit, and one of those 3 issues could cause that.

-Eric

Tue, 06/15/2010 - 09:47
danhole

It is named.procmail

it is in the users home dir

it is being hit because the log says

procmail: Executing "/usr/sbin/sendmail,-oi,first.last@domain.local"

but the message never gets there ?

Tue, 06/15/2010 - 09:52
andreychek

Howdy,

After sending it an email, you may want to look in the email log to figure out what's going awry... it's in either /var/log/maillog or /var/log/mail.log.

-Eric

Tue, 06/15/2010 - 10:27
danhole

Thanks for that Eric here is a copy of my maillog for a message coming in and then failing to forward it does have some failures at the end, i have looked these up but not got very far.

i cannot work out why it works fine for a new user i setup very strange.

the issue looks to be when procmail send it to sendmail, if i manually pipe the message to this command it works fine? postfix/sendmail[11839]: fatal: first.last@domain.com(539): queue file write error

Jun 15 16:12:29 mail postfix/smtpd[11247]: connection established Jun 15 16:12:29 mail postfix/smtpd[11247]: master_notify: status 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: name_mask: resource Jun 15 16:12:29 mail postfix/smtpd[11247]: name_mask: software Jun 15 16:12:29 mail postfix/smtpd[11247]: xsasl_dovecot_server_create: SASL service=smtp, realm=(null) Jun 15 16:12:29 mail postfix/smtpd[11247]: connect from mail.sendersdomain.com[100.000.000.000] Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: mail.sendersdomain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: 100.000.000.000: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: mail.sendersdomain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: 100.000.000.000: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostname: mail.sendersdomain.com ~? domain.local Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostaddr: 100.000.000.000 ~? domain.local Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: mail.sendersdomain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: 100.000.000.000: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostname: mail.sendersdomain.com ~? 127.0.0.0/8 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostaddr: 100.000.000.000 ~? 127.0.0.0/8 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostname: mail.sendersdomain.com ~? 172.30.254.0/24 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostaddr: 100.000.000.000 ~? 172.30.254.0/24 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: mail.sendersdomain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: 100.000.000.000: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr request = connect Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr ident = smtp:100.000.000.000 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/anvil: wanted attribute: status Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: status Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/anvil: wanted attribute: count Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: count Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 1 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/anvil: wanted attribute: rate Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: rate Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 1 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/anvil: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 220 mail.domain.com ESMTP Postfix Jun 15 16:12:29 mail postfix/smtpd[11247]: < mail.sendersdomain.com[100.000.000.000]: EHLO sendersdomain.co.uk Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-mail.domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-PIPELINING Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-SIZE 10240000 Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-VRFY Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-ETRN Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-AUTH PLAIN LOGIN Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: mail.sendersdomain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: 100.000.000.000: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-AUTH=PLAIN LOGIN Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-ENHANCEDSTATUSCODES Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250-8BITMIME Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250 DSN Jun 15 16:12:29 mail postfix/smtpd[11247]: < mail.sendersdomain.com[100.000.000.000]: MAIL From:first.last@sendersdomain.com SIZE=38677 Jun 15 16:12:29 mail postfix/smtpd[11247]: extract_addr: input: first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: smtpd_check_addr: addr=first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr request = rewrite Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr rule = local Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr address = first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: address Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: address Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: rewrite_clnt: local: first.last@sendersdomain.com -> first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr request = resolve Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr sender = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr address = first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: transport Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: transport Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: smtp Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: nexthop Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: nexthop Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: recipient Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: recipient Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 4096 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: resolve_clnt: ' ->first.last@sendersdomain.com' -> transp=smtp' host=sendersdomain.com' rcpt=first.last@sendersdomain.com' flags= class=default Jun 15 16:12:29 mail postfix/smtpd[11247]: ctable_locate: install entry key first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: extract_addr: in: <first.last@sendersdomain.com>, result: first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: fsspace: .: block size 4096, blocks free 4915968 Jun 15 16:12:29 mail postfix/smtpd[11247]: smtpd_check_queue: blocks 4096 avail 4915968 min_free 0 msg_size_limit 10240000 Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250 2.1.0 Ok Jun 15 16:12:29 mail postfix/smtpd[11247]: < mail.sendersdomain.com[100.000.000.000]: RCPT To:<first.last@domain.com> Jun 15 16:12:29 mail postfix/smtpd[11247]: extract_addr: input: <first.last@domain.com> Jun 15 16:12:29 mail postfix/smtpd[11247]: smtpd_check_addr: addr=first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr request = rewrite Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr rule = local Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr address = first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: address Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: address Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: rewrite_clnt: local: first.last@domain.com -> first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr request = resolve Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr sender = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr address = first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: transport Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: transport Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: error Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: nexthop Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: nexthop Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: User unknown in virtual alias table Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: recipient Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: recipient Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: flags Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 512 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/rewrite socket: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: resolve_clnt:' -> first.last@domain.com' -> transp=error' host=User unknown in virtual alias table' rcpt=first.last@domain.com' flags= class=alias Jun 15 16:12:29 mail postfix/smtpd[11247]: ctable_locate: install entry key first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: extract_addr: in: first.last@domain.com, result: first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: >>> START Recipient address RESTRICTIONS <<< Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=permit_mynetworks Jun 15 16:12:29 mail postfix/smtpd[11247]: permit_mynetworks: mail.sendersdomain.com 100.000.000.000 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostname: mail.sendersdomain.com ~? 127.0.0.0/8 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostaddr: 100.000.000.000 ~? 127.0.0.0/8 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostname: mail.sendersdomain.com ~? 172.30.254.0/24 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostaddr: 100.000.000.000 ~? 172.30.254.0/24 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: mail.sendersdomain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: 100.000.000.000: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=permit_mynetworks status=0 Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=permit_sasl_authenticated Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=permit_sasl_authenticated status=0 Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=reject_unauth_destination Jun 15 16:12:29 mail postfix/smtpd[11247]: reject_unauth_destination: first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: permit_auth_destination: first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: ctable_locate: leave existing entry key first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=reject_unauth_destination status=0 Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=check_policy_service Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr request = smtpd_access_policy Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr protocol_state = RCPT Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr protocol_name = ESMTP Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr client_address = 100.000.000.000 Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr client_name = mail.sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr reverse_client_name = mail.sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr helo_name = sendersdomain.co.uk Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr sender = first.last@sendersdomain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr recipient = first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr recipient_count = 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr queue_id = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr instance = 2bef.4c17985d.d9a1d.0 Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr size = 38677 Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr etrn_domain = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr sasl_method = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr sasl_username = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr sasl_sender = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr ccert_subject = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr ccert_issuer = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr ccert_fingerprint = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr encryption_protocol = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr encryption_cipher = Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr encryption_keysize = 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: /var/spool/postfix/postgrey/socket: wanted attribute: action Jun 15 16:12:29 mail postgrey[31459]: action=pass, reason=client AWL, client_name=mail.sendersdomain.com, client_address=100.000.000.000, sender=first.last@sendersdomain.com, recipient=first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: action Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: DUNNO Jun 15 16:12:29 mail postfix/smtpd[11247]: /var/spool/postfix/postgrey/socket: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: check_table_result: unix:/var/spool/postfix/postgrey/socket DUNNO policy query Jun 15 16:12:29 mail postfix/smtpd[11247]: generic_checks: name=check_policy_service status=0 Jun 15 16:12:29 mail postfix/smtpd[11247]: >>> END Recipient address RESTRICTIONS <<< Jun 15 16:12:29 mail postfix/smtpd[11247]: >>> CHECKING RECIPIENT MAPS <<< Jun 15 16:12:29 mail postfix/smtpd[11247]: ctable_locate: leave existing entry key first.last@domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: maps_find: recipient_canonical_maps: first.last@domain.com: not found Jun 15 16:12:29 mail postfix/smtpd[11247]: match_string: domain.com ~? mail.domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: match_string: domain.com ~? localhost.domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: match_string: domain.com ~? localhost Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: domain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: maps_find: recipient_canonical_maps: @domain.com: not found Jun 15 16:12:29 mail postfix/smtpd[11247]: mail_addr_find: first.last@domain.com -> (not found) Jun 15 16:12:29 mail postfix/smtpd[11247]: maps_find: canonical_maps: first.last@domain.com: not found Jun 15 16:12:29 mail postfix/smtpd[11247]: match_string: domain.com ~? mail.domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: match_string: domain.com ~? localhost.domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: match_string: domain.com ~? localhost Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: domain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: maps_find: canonical_maps: @domain.com: not found Jun 15 16:12:29 mail postfix/smtpd[11247]: mail_addr_find: first.last@domain.com -> (not found) Jun 15 16:12:29 mail postfix/smtpd[11247]: maps_find: virtual_alias_maps: hash:/etc/postfix/virtual(0,lock|fold_fix): first.last@domain.com = first.last-domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: mail_addr_find: first.last@domain.com -> first.last-domain.com Jun 15 16:12:29 mail postfix/smtpd[11247]: smtpd_check_rewrite: trying: permit_inet_interfaces Jun 15 16:12:29 mail postfix/smtpd[11247]: permit_inet_interfaces: mail.sendersdomain.com 100.000.000.000 Jun 15 16:12:29 mail postfix/smtpd[11247]: before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters Jun 15 16:12:29 mail postfix/smtpd[11247]: after input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping Jun 15 16:12:29 mail postfix/smtpd[11247]: connect to subsystem public/cleanup Jun 15 16:12:29 mail postfix/smtpd[11247]: public/cleanup socket: wanted attribute: queue_id Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: queue_id Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: DB5F213720E Jun 15 16:12:29 mail postfix/smtpd[11247]: public/cleanup socket: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr flags = 50 Jun 15 16:12:29 mail postfix/smtpd[11247]: DB5F213720E: client=mail.sendersdomain.com[100.000.000.000] Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250 2.1.5 Ok Jun 15 16:12:29 mail postfix/smtpd[11247]: < mail.sendersdomain.com[100.000.000.000]: DATA Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 354 End data with . Jun 15 16:12:29 mail postfix/cleanup[11376]: DB5F213720E: message-id=62EC24576A229346A2398E3466E25B1B27FFAB@marvel.sendersdomain.local Jun 15 16:12:29 mail postfix/smtpd[11247]: public/cleanup socket: wanted attribute: status Jun 15 16:12:29 mail postfix/qmgr[11364]: DB5F213720E: from=first.last@sendersdomain.com, size=38888, nrcpt=1 (queue active) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: status Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: public/cleanup socket: wanted attribute: reason Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: reason Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: public/cleanup socket: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 250 2.0.0 Ok: queued as DB5F213720E Jun 15 16:12:29 mail postfix/smtpd[11247]: < mail.sendersdomain.com[100.000.000.000]: QUIT Jun 15 16:12:29 mail postfix/smtpd[11247]: > mail.sendersdomain.com[100.000.000.000]: 221 2.0.0 Bye Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostname: mail.sendersdomain.com ~? 127.0.0.0/8 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostaddr: 100.000.000.000 ~? 127.0.0.0/8 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostname: mail.sendersdomain.com ~? 172.30.254.0/24 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_hostaddr: 100.000.000.000 ~? 172.30.254.0/24 Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: mail.sendersdomain.com: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: match_list_match: 100.000.000.000: no match Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr request = disconnect Jun 15 16:12:29 mail postfix/smtpd[11247]: send attr ident = smtp:100.000.000.000 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/anvil: wanted attribute: status Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: status Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute value: 0 Jun 15 16:12:29 mail postfix/smtpd[11247]: private/anvil: wanted attribute: (list terminator) Jun 15 16:12:29 mail postfix/smtpd[11247]: input attribute name: (end) Jun 15 16:12:29 mail postfix/smtpd[11247]: disconnect from mail.sendersdomain.com[100.000.000.000] Jun 15 16:12:29 mail postfix/smtpd[11247]: master_notify: status 1 Jun 15 16:12:29 mail postfix/smtpd[11247]: connection closed Jun 15 16:12:30 mail spamd[506]: spamd: connection from localhost.localdomain [127.0.0.1] at port 39678 Jun 15 16:12:30 mail spamd[506]: spamd: setuid to first.last@domain.com succeeded Jun 15 16:12:30 mail spamd[506]: spamd: processing message 62EC24576A229346A2398E3466E25B1B27FFAB@marvel.sendersdomain.local for first.last@domain.com:539 Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 603. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in pattern match (m//) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 621. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 622. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 623. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 624. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 603. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in pattern match (m//) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 621. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 622. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 623. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 624. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 603. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in pattern match (m//) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 621. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 622. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 623. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 624. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 603. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in pattern match (m//) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 621. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 622. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 623. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 624. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 603. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in pattern match (m//) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 604. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 621. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in substitution (s///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 622. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in transliteration (tr///) at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 623. Jun 15 16:12:30 mail spamd[506]: Use of uninitialized value in length at /usr/lib/perl5/vendor_perl/5.8.8/Mail/SpamAssassin/Util.pm line 624. Jun 15 16:12:30 mail spamd[506]: spamd: clean message (1.0/5.0) for first.last@domain.com:539 in 0.2 seconds, 38436 bytes. Jun 15 16:12:30 mail spamd[506]: spamd: result: . 0 - AWL,EXTRA_MPART_TYPE,HTML_MESSAGE scantime=0.2,size=38436,user=first.last@domain.com,uid=539,required_score=5.0,rhost=localhost.localdomain,raddr=127.0.0.1,rport=39678,mid=62EC24576A229346A2398E3466E25B1B27FFAB@marvel.sendersdomain.local,autolearn=no Jun 15 15:12:30 mail postfix/postdrop[11840]: warning: uid=539: Illegal seek Jun 15 16:12:30 mail postfix/sendmail[11839]: fatal: first.last@domain.com(539): queue file write error Jun 15 16:12:30 mail spamd[25727]: prefork: child states: II Jun 15 16:12:30 mail postfix/local[11650]: DB5F213720E: to=first.last-domain.com@mail.domain.com, orig_to=first.last@domain.com, relay=local, delay=0.42, delays=0.07/0/0/0.35, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME) Jun 15 16:12:30 mail postfix/qmgr[11364]: DB5F213720E: removed

Tue, 06/15/2010 - 10:57
andreychek

Howdy,

Well, that's an awful lot of information to sort through in the forums here... however, two things stand out:

first.last@domain.com'  transp=error' host=User unknown in virtual alias table' rcpt=first.last@domain.com'

The user unknown error suggests that Postfix doesn't think that's a valid user. You may want to double-check that the user exists, is spelled correctly, and has email enabled.

Secondly, I see this:

warning: uid=539: Illegal seek Jun 15 16:12:30 mail postfix/sendmail[11839]: fatal: first.last@domain.com(539): queue file write error

That suggests that a particular large email is being sent to them, or that perhaps the quota is filling up. You may want to verify that the quota is large enough, and make sure you're doing the test with a small email, not including an attachment of any sort.

-Eric

Wed, 06/16/2010 - 04:47
danhole

Eric,

The message is delivered to the users actual mailbox so this is working however the forwarded message isnt forwarded.

The test message i sent was html with my signiture so did have a few attachments.

When i send it in plain txt with no attachments the message changes from Illegal seek to Disk quota exceeded

it is nowhere near the disk quota, the users dont have quota's

Jun 16 08:11:10 mail postfix/postdrop[29856]: warning: uid=539: Disk quota exceeded
Jun 16 09:11:10 mail postfix/sendmail[29855]: fatal: first.last@domain.com(539): queue file write error
Wed, 06/16/2010 - 08:14
andreychek

Well, even if your individual email users don't have disk quotas, the Virtual Server itself may have a quota of some sort.

In Virtualmin, after selecting your domain from the dropdown list, click Edit Virtual Server -> Quotas and limits.

Is there a "Total Server Quota" setup there?

-Eric

Thu, 06/17/2010 - 03:22
danhole

under quota's i have the bandwith limit set to unlimited

Thu, 06/17/2010 - 08:47
andreychek

Well, it wouldn't be the bandwidth limit, the issue you're seeing is a disk quota related problem... so you'll want to take a look at the option labeled "Total server quota", which holds the disk quota for your Virtual Server.

-Eric

Topic locked