Problems receiving mail on 54

[Hayden Parker]

Hello,

I recently installed mailserv on 5.4.  While I am able to send mail totally fine, I am unable to receive mail.  Here is the ouput from maillog when the message hits my server:

Jun 29 22:26:07 hkparker postfix/smtpd[19015]: connect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/smtpd[19015]: C1EBC65EE: client=mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/cleanup[25617]: C1EBC65EE: message-id=<CA+rnqWX2dR69rT824JOuFc6q...@mail.gmail.com>

Jun 29 22:26:09 hkparker postfix/qmgr[9366]: C1EBC65EE: from=<hayden...@gmail.com>, size=1889, nrcpt=1 (queue active)

Jun 29 22:26:09 hkparker spamd[15601]: spamd: connection from localhost [127.0.0.1] at port 47613 

Jun 29 22:26:09 hkparker spamd[15601]: spamd: processing message <CA+rnqWX2dR69rT824JOuFc6q...@mail.gmail.com> for hay...@hkparker.com:62 

Jun 29 22:26:09 hkparker postfix/smtpd[19015]: disconnect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:13 hkparker spamd[15601]: spamd: clean message (0.6/5.0) for hay...@hkparker.com:62 in 4.5 seconds, 1852 bytes. 

Jun 29 22:26:13 hkparker spamd[15601]: spamd: result: . 0 - DKIM_ADSP_CUSTOM_MED,DKIM_SIGNED,FREEMAIL_FROM,HTML_MESSAGE,NML_ADSP_CUSTOM_MED,RCVD_IN_DNSWL_LOW,SPF_PASS,T_DKIM_INVALID,T_TO_NO_BRKTS_FREEMAIL scantime=4.5,size=1852,user=hay...@hkparker.com,uid=62,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=47613,mid=<CA+rnqWX2dR69rT824JOuFc6q...@mail.gmail.com>,autolearn=no 

Jun 29 22:26:13 hkparker spamd[3507]: prefork: child states: II 

Jun 29 22:26:13 hkparker postfix/pickup[27062]: C4A1165F0: uid=506 from=<hayden...@gmail.com>

Jun 29 22:26:13 hkparker postfix/pipe[9162]: C1EBC65EE: to=<hay...@hkparker.com>, relay=spamassassin, delay=6, delays=1.4/0.01/0/4.6, dsn=2.0.0, status=sent (delivered via spamassassin service)

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C1EBC65EE: removed

Jun 29 22:26:13 hkparker postfix/cleanup[25617]: C4A1165F0: message-id=<CA+rnqWX2dR69rT824JOuFc6q...@mail.gmail.com>

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C4A1165F0: from=<hayden...@gmail.com>, size=2276, nrcpt=1 (queue active)

Jun 29 22:26:13 hkparker postfix/local[155]: warning: error looking up passwd info for hayden: Operation not permitted

Jun 29 22:26:13 hkparker postfix/local[155]: C4A1165F0: to=<hay...@hkparker.com>, relay=local, delay=0.04, delays=0.02/0.01/0/0.01, dsn=4.0.0, status=deferred (user lookup error)

Could this line be the problem?

Jun 29 22:26:13 hkparker postfix/local[155]: warning: error looking up passwd info for hayden: Operation not permitted.

I've been searching for a few days now but haven't been able to find anything, has anyone else had this experience with 54 or have any recommendations?

Thank you,

Hayden

[David Gnojek]

Hi Hayden,

did you use a webmail or a client for receiving?

David

--
You received this message because you are subscribed to the Google Groups "mailserv" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mailserv+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Hayden Parker]

Web mail, I logged into roundcube with that account.  I'd be happy to try connecting with an IMAP client and see if I can see mail if you'd like, but I believe roundcube is working and the problem is postfix.  I did verify that main.cf pointed to a users file, which contained valid credentials to a mysql database with the user in it.

Thank for the help,

Hayden

On Monday, June 30, 2014 8:43:01 AM UTC-7, david wrote:

Hi Hayden,

did you use a webmail or a client for receiving?

David

On Mon, Jun 30, 2014 at 7:52 AM, Hayden Parker <hayden...@gmail.com> wrote:

Hello,

I recently installed mailserv on 5.4.  While I am able to send mail totally fine, I am unable to receive mail.  Here is the ouput from maillog when the message hits my server:

Jun 29 22:26:07 hkparker postfix/smtpd[19015]: connect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/smtpd[19015]: C1EBC65EE: client=mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/cleanup[25617]: C1EBC65EE: message-id=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com>

Jun 29 22:26:09 hkparker postfix/qmgr[9366]: C1EBC65EE: from=<hayden...@gmail.com>, size=1889, nrcpt=1 (queue active)

Jun 29 22:26:09 hkparker spamd[15601]: spamd: connection from localhost [127.0.0.1] at port 47613 

Jun 29 22:26:09 hkparker spamd[15601]: spamd: processing message <CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com> for hay...@hkparker.com:62 

Jun 29 22:26:09 hkparker postfix/smtpd[19015]: disconnect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:13 hkparker spamd[15601]: spamd: clean message (0.6/5.0) for hay...@hkparker.com:62 in 4.5 seconds, 1852 bytes. 

Jun 29 22:26:13 hkparker spamd[15601]: spamd: result: . 0 - DKIM_ADSP_CUSTOM_MED,DKIM_SIGNED,FREEMAIL_FROM,HTML_MESSAGE,NML_ADSP_CUSTOM_MED,RCVD_IN_DNSWL_LOW,SPF_PASS,T_DKIM_INVALID,T_TO_NO_BRKTS_FREEMAIL scantime=4.5,size=1852,user=hayd...@hkparker.com,uid=62,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=47613,mid=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com>,autolearn=no 

Jun 29 22:26:13 hkparker spamd[3507]: prefork: child states: II 

Jun 29 22:26:13 hkparker postfix/pickup[27062]: C4A1165F0: uid=506 from=<hayden...@gmail.com>

Jun 29 22:26:13 hkparker postfix/pipe[9162]: C1EBC65EE: to=<hay...@hkparker.com>, relay=spamassassin, delay=6, delays=1.4/0.01/0/4.6, dsn=2.0.0, status=sent (delivered via spamassassin service)

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C1EBC65EE: removed

Jun 29 22:26:13 hkparker postfix/cleanup[25617]: C4A1165F0: message-id=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com>

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C4A1165F0: from=<hayden...@gmail.com>, size=2276, nrcpt=1 (queue active)

Jun 29 22:26:13 hkparker postfix/local[155]: warning: error looking up passwd info for hayden: Operation not permitted

Jun 29 22:26:13 hkparker postfix/local[155]: C4A1165F0: to=<hay...@hkparker.com>, relay=local, delay=0.04, delays=0.02/0.01/0/0.01, dsn=4.0.0, status=deferred (user lookup error)

Could this line be the problem?

Jun 29 22:26:13 hkparker postfix/local[155]: warning: error looking up passwd info for hayden: Operation not permitted.

I've been searching for a few days now but haven't been able to find anything, has anyone else had this experience with 54 or have any recommendations?

Thank you,

Hayden

[Hayden Parker]

I was able to remove the user lookup error by creating a local user with the same name.  I'm not sure why this was necessary since postfix was set to authenticate against mysql and there was a user there, but I'm just glad thats working.  Things are still not showing up in roundcube however.

[Hayden Parker]

It looks like the mail is being delivered to my local mailbox now (visible when running the "mail" command), but that is not the mailbox roundcube is configured to use.

[David Gnojek]

trying to somehow simulate this problem

if you were able to log in to rcube it looks like account credentials will be there in mysql (in DB mail uder table users).

+ What I would test if there exists home folder and if has proper rights ownership in /var/mailserv/mail/your.domain/yourmailbox (the owner and owner group should be >= 2000 and should match with id in users table.

+  did you try f.e. to create a new email address under same domain and try to send/receive something?

+ can you pls check what is in /var/log/mailog_webmin

Cheers
David

On Wed, Jul 2, 2014 at 1:05 AM, Hayden Parker <hayden...@gmail.com> wrote:

It looks like the mail is being delivered to my local mailbox now (visible when running the "mail" command), but that is not the mailbox roundcube is configured to use.

--

[Hayden Parker]

Thank you for the help.

The credentials I used to login to roundcube are in the user table of the mail database correctly.

/var/mailserv/mail/my.domain/mymailbox is owned by 2000:2000, same id as in the database and administrative page for that user.

I'll try creating another account and repeating the process, the problems I'm having are with the first account I created.

maillog_webmin shows the same thing as maillog:

Jul  1 16:14:30 hkparker postfix/smtpd[4876]: connect from mail-qg0-f42.google.com[209.85.192.42]

Jul  1 16:14:31 hkparker postfix/smtpd[4876]: B88111965E: client=mail-qg0-f42.google.com[209.85.192.42]

Jul  1 16:14:31 hkparker postfix/cleanup[10785]: B88111965E: message-id=<CA+rnqWVLr206pOgiC2FkS23P...@mail.gmail.com>

Jul  1 16:14:31 hkparker postfix/qmgr[15091]: B88111965E: from=<hayden...@gmail.com>, size=1881, nrcpt=1 (queue active)

Jul  1 16:14:31 hkparker spamd[3656]: spamd: connection from localhost [127.0.0.1] at port 9632 

Jul  1 16:14:31 hkparker spamd[3656]: spamd: processing message <CA+rnqWVLr206pOgiC2FkS23P...@mail.gmail.com> for hay...@hkparker.com:62 

Jul  1 16:14:32 hkparker postfix/smtpd[4876]: disconnect from mail-qg0-f42.google.com[209.85.192.42]

Jul  1 16:14:35 hkparker spamd[3656]: spamd: clean message (1.3/5.0) for hay...@hkparker.com:62 in 3.1 seconds, 1847 bytes. 

Jul  1 16:14:35 hkparker spamd[3656]: spamd: result: . 1 - DKIM_ADSP_CUSTOM_MED,DKIM_SIGNED,FREEMAIL_FROM,HTML_MESSAGE,NML_ADSP_CUSTOM_MED,RCVD_IN_DNSWL_NONE,SPF_PASS,T_DKIM_INVALID scantime=3.1,size=1847,user=hay...@hkparker.com,uid=62,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=9632,mid=<CA+rnqWVLr206pOgiC2FkS23P...@mail.gmail.com>,autolearn=no 

Jul  1 16:14:35 hkparker spamd[27758]: prefork: child states: IIIII 

Jul  1 16:14:35 hkparker postfix/pickup[9720]: 1A0F419709: uid=506 from=<hayden...@gmail.com>

Jul  1 16:14:35 hkparker postfix/pipe[12188]: B88111965E: to=<hay...@hkparker.com>, relay=spamassassin, delay=4, delays=0.83/0.01/0/3.1, dsn=2.0.0, status=sent (delivered via spamassassin service)

Jul  1 16:14:35 hkparker postfix/qmgr[15091]: B88111965E: removed

Jul  1 16:14:35 hkparker postfix/cleanup[10785]: 1A0F419709: message-id=<CA+rnqWVLr206pOgiC2FkS23P...@mail.gmail.com>

Jul  1 16:14:35 hkparker postfix/qmgr[15091]: 1A0F419709: from=<hayden...@gmail.com>, size=2251, nrcpt=1 (queue active)

Jul  1 16:14:35 hkparker postfix/local[6995]: 1A0F419709: to=<hay...@hkparker.com>, relay=local, delay=0.03, delays=0.02/0.01/0/0, dsn=2.0.0, status=sent (delivered to mailbox)

Jul  1 16:14:35 hkparker postfix/qmgr[15091]: 1A0F419709: removed

Let me know if there's anything else you need.

Thank you,

Hayden

[Hayden Parker]

I created a new account and as expected I see the error:

warning: error looking up passwd info for <user>: Operation not permitted

because I haven't created a local account for the user.  But creating a local account should not be necessary, should it?

On Sunday, June 29, 2014 10:52:12 PM UTC-7, Hayden Parker wrote:

Hello,

I recently installed mailserv on 5.4.  While I am able to send mail totally fine, I am unable to receive mail.  Here is the ouput from maillog when the message hits my server:

Jun 29 22:26:07 hkparker postfix/smtpd[19015]: connect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/smtpd[19015]: C1EBC65EE: client=mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/cleanup[25617]: C1EBC65EE: message-id=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com>

Jun 29 22:26:09 hkparker postfix/qmgr[9366]: C1EBC65EE: from=<hayden...@gmail.com>, size=1889, nrcpt=1 (queue active)

Jun 29 22:26:09 hkparker spamd[15601]: spamd: connection from localhost [127.0.0.1] at port 47613 

Jun 29 22:26:09 hkparker spamd[15601]: spamd: processing message <CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com> for hay...@hkparker.com:62 

Jun 29 22:26:09 hkparker postfix/smtpd[19015]: disconnect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:13 hkparker spamd[15601]: spamd: clean message (0.6/5.0) for hay...@hkparker.com:62 in 4.5 seconds, 1852 bytes. 

Jun 29 22:26:13 hkparker spamd[15601]: spamd: result: . 0 - DKIM_ADSP_CUSTOM_MED,DKIM_SIGNED,FREEMAIL_FROM,HTML_MESSAGE,NML_ADSP_CUSTOM_MED,RCVD_IN_DNSWL_LOW,SPF_PASS,T_DKIM_INVALID,T_TO_NO_BRKTS_FREEMAIL scantime=4.5,size=1852,user=hayd...@hkparker.com,uid=62,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=47613,mid=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com>,autolearn=no 

Jun 29 22:26:13 hkparker spamd[3507]: prefork: child states: II 

Jun 29 22:26:13 hkparker postfix/pickup[27062]: C4A1165F0: uid=506 from=<hayden...@gmail.com>

Jun 29 22:26:13 hkparker postfix/pipe[9162]: C1EBC65EE: to=<hay...@hkparker.com>, relay=spamassassin, delay=6, delays=1.4/0.01/0/4.6, dsn=2.0.0, status=sent (delivered via spamassassin service)

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C1EBC65EE: removed

Jun 29 22:26:13 hkparker postfix/cleanup[25617]: C4A1165F0: message-id=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC...@mail.gmail.com>

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C4A1165F0: from=<hayden...@gmail.com>, size=2276, nrcpt=1 (queue active)

Jun 29 22:26:13 hkparker postfix/local[155]: warning: error looking up passwd info for hayden: Operation not permitted

Jun 29 22:26:13 hkparker postfix/local[155]: C4A1165F0: to=<hay...@hkparker.com>, relay=local, delay=0.04, delays=0.02/0.01/0/0.01, dsn=4.0.0, status=deferred (user lookup error)

[David Gnojek]

definitely not necessary to create a local user account. normally all you have to do is create account under web administration. 

looks like its trying to authorize the user against local passwd, thats happens when failed auth against mysql which has higher priority in main.cf

can you check if postfix main.cf is same like here https://github.com/mailserv/mailserv/blob/5.4/install/templates/postfix/main.cf

and then if exists a file /etc/postfix/sql/user.cf in your system. It should looks like this https://github.com/mailserv/mailserv/blob/5.4/install/templates/postfix/sql/user.cf

[Hayden Parker]

All of those files exist exactly like their templates on github (except I had to comment out this line to prevent every message being spam filtered).

I can use the credentials defined in user.cf to login to mysql, and the correct information exists in the correct table.

I'll try commenting out the local authentication and see what happens.

Thanks again,

Hayden

On Thursday, July 3, 2014 7:44:57 AM UTC-7, david wrote:

definitely not necessary to create a local user account. normally all you have to do is create account under web administration. 

looks like its trying to authorize the user against local passwd, thats happens when failed auth against mysql which has higher priority in main.cf

can you check if postfix main.cf is same like here https://github.com/mailserv/mailserv/blob/5.4/install/templates/postfix/main.cf

and then if exists a file /etc/postfix/sql/user.cf in your system. It should looks like this https://github.com/mailserv/mailserv/blob/5.4/install/templates/postfix/sql/user.cf

On Wed, Jul 2, 2014 at 6:01 PM, Hayden Parker <hayden...@gmail.com> wrote:

I created a new account and as expected I see the error:

warning: error looking up passwd info for <user>: Operation not permitted

because I haven't created a local account for the user.  But creating a local account should not be necessary, should it?

On Sunday, June 29, 2014 10:52:12 PM UTC-7, Hayden Parker wrote:

Hello,

I recently installed mailserv on 5.4.  While I am able to send mail totally fine, I am unable to receive mail.  Here is the ouput from maillog when the message hits my server:

Jun 29 22:26:07 hkparker postfix/smtpd[19015]: connect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/smtpd[19015]: C1EBC65EE: client=mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:08 hkparker postfix/cleanup[25617]: C1EBC65EE: message-id=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC6O...@mail.gmail.com>

Jun 29 22:26:09 hkparker postfix/qmgr[9366]: C1EBC65EE: from=<hayden...@gmail.com>, size=1889, nrcpt=1 (queue active)

Jun 29 22:26:09 hkparker spamd[15601]: spamd: connection from localhost [127.0.0.1] at port 47613 

Jun 29 22:26:09 hkparker spamd[15601]: spamd: processing message <CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC6O4Di61Xg@mail.gmail.com> for hay...@hkparker.com:62 

Jun 29 22:26:09 hkparker postfix/smtpd[19015]: disconnect from mail-qa0-f53.google.com[209.85.216.53]

Jun 29 22:26:13 hkparker spamd[15601]: spamd: clean message (0.6/5.0) for hay...@hkparker.com:62 in 4.5 seconds, 1852 bytes. 

Jun 29 22:26:13 hkparker spamd[15601]: spamd: result: . 0 - DKIM_ADSP_CUSTOM_MED,DKIM_SIGNED,FREEMAIL_FROM,HTML_MESSAGE,NML_ADSP_CUSTOM_MED,RCVD_IN_DNSWL_LOW,SPF_PASS,T_DKIM_INVALID,T_TO_NO_BRKTS_FREEMAIL scantime=4.5,size=1852,user=hayd...@hkparker.com,uid=62,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=47613,mid=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC6O4Di61Xg@mail.gmail.com>,autolearn=no 

Jun 29 22:26:13 hkparker spamd[3507]: prefork: child states: II 

Jun 29 22:26:13 hkparker postfix/pickup[27062]: C4A1165F0: uid=506 from=<hayden...@gmail.com>

Jun 29 22:26:13 hkparker postfix/pipe[9162]: C1EBC65EE: to=<hay...@hkparker.com>, relay=spamassassin, delay=6, delays=1.4/0.01/0/4.6, dsn=2.0.0, status=sent (delivered via spamassassin service)

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C1EBC65EE: removed

Jun 29 22:26:13 hkparker postfix/cleanup[25617]: C4A1165F0: message-id=<CA+rnqWX2dR69rT824JOuFc6qJjD7UbpqBE8+hXAYC6O...@mail.gmail.com>

Jun 29 22:26:13 hkparker postfix/qmgr[9366]: C4A1165F0: from=<hayden...@gmail.com>, size=2276, nrcpt=1 (queue active)

Jun 29 22:26:13 hkparker postfix/local[155]: warning: error looking up passwd info for hayden: Operation not permitted

Jun 29 22:26:13 hkparker postfix/local[155]: C4A1165F0: to=<hay...@hkparker.com>, relay=local, delay=0.04, delays=0.02/0.01/0/0.01, dsn=4.0.0, status=deferred (user lookup error)

Could this line be the problem?

Jun 29 22:26:13 hkparker postfix/local[155]: warning: error looking up passwd info for hayden: Operation not permitted.

I've been searching for a few days now but haven't been able to find anything, has anyone else had this experience with 54 or have any recommendations?

Thank you,

Hayden

[Hayden Parker]

Interesting results when I commented out lines 66 and 67 of main.cf:

Jul  3 14:44:54 hkparker postfix/proxymap[10178]: warning: request for unapproved table: "unix:passwd.byname"

Jul  3 14:44:54 hkparker postfix/proxymap[10178]: warning: to approve this table for read-only access, list proxy:unix:passwd.byname in main.cf:proxy_read_maps

Jul  3 14:44:54 hkparker postfix/smtpd[29050]: fatal: proxymap service is not configured for table "unix:passwd.byname"

Jul  3 14:44:55 hkparker postfix/master[18252]: warning: process /usr/local/libexec/postfix/smtpd pid 29050 exit status 1

[David Gnojek]

can you check mysql logs /var/log/mysql.log and mysql access rights for postfix.  It should looks like this:

mysql> show grants for postfix@localhost;
+----------------------------------------------------------------------------------------------------------------+
| Grants for postfix@localhost                                                                                   |
+----------------------------------------------------------------------------------------------------------------+
| GRANT USAGE ON *.* TO 'postfix'@'localhost' IDENTIFIED BY PASSWORD '*33E0762B574AF0FEB01F6B5410648D3C62C6C017' |
| GRANT SELECT ON `mail`.* TO 'postfix'@'localhost' 

if this is missing try to push this lines:
 

/usr/local/bin/mysql -e "grant select on mail.* to 'postfix'@'localhost' identified by 'postfix';"
/usr/local/bin/mysql -e "grant all privileges on mail.* to 'mailadmin'@'localhost' identified by 'mailadmin';"

I think if postifix is refused by mysql because of access rights, when it tries to validate the user it skips for next auth method.