Clarify README to describe where token file goes, and what goes into sasl_passwd, if chroot is enabled

agrigittest commented 4 years ago

Hello,

I don't know if it is the right place to ask for some help, but there is not much info about posfix and Oauth2 mechanisme out there so i jus try, sorry if i'm not supposed to.

I'm trying to get Xoauth2 work together with postfix and Gmail And encouter the followin error :

sasl-xoauth2: 2020-04-15 15:03:26:TokenStore::Read: file=/etc/tokens/[username] sasl-xoauth2: 2020-04-15 15:03:26 : TokenStore::Read: failed to open file /etc/tokens/[username]

The acces right are as follow :

-rw-r--r-- 1 postfix postfix 341 avril 15 14:10 [username]

i have tried to give full acces for testing purpose to the whole directory but no luck !

i'm working on ubuntu 18 TLS with the ubuntu package : sasl-xoauth2/stable

And postfix configured according the readme file.

Can you please help me ?

Kind regards

tarickb commented 4 years ago

Do you have your token file in /etc/tokens/[username], or in /var/spool/postfix/etc/tokens/[username]? If you have chroot enabled for Postfix, the tokens will usually end up being in /var/spool/postfix/etc/tokens instead of /etc/tokens.

agrigittest commented 4 years ago

Hi,

Thanks for reply,

I have tested both locations, actually i'm using etc/tokens/[username]. My postfix is not chrooted. I have setup the tokens path in /etc/postfix.sasl_passwd, then postmap the file

Regarding documentation it should work. I do not understand the error message as file is availlable and read/writeable for postfix

any hint ?

tarickb commented 4 years ago

Did you generate an initial token? That error message can also indicate that the file is empty. Your token file should contain something like:

{ "access_token" : "...", "expiry" : "0", "refresh_token" : "1/..." }

Can you copy the results of stat /etc/tokens and stat /etc/tokens/[username]?

agrigittest commented 4 years ago

Of course i did generate the initial token and tested it with the python script The content of the token file is ok

I noticed that the error is the same even if file is present or not

Here is the stat output for the driectoory and token file

stat /etc/tokens/ File: /etc/tokens/ Size: 4096 Blocks: 8 IO Block: 4096 directory Device: fc02h/64514d Inode: 410656 Links: 2 Access: (0660/drw-rw----) Uid: ( 111/ postfix) Gid: ( 114/ postfix) Access: 2020-04-16 14:15:10.668764155 +0000 Modify: 2020-04-16 14:14:51.444630313 +0000 Change: 2020-04-16 14:15:10.668764155 +0000 Birth: -

File: /etc/tokens/[username] Size: 341 Blocks: 8 IO Block: 4096 regular file Device: fc02h/64514d Inode: 394419 Links: 1 Access: (0751/-rwxr-x--x) Uid: ( 111/ postfix) Gid: ( 114/ postfix) Access: 2020-04-16 14:14:51.444630313 +0000 Modify: 2020-04-16 14:14:51.444630313 +0000 Change: 2020-04-16 14:15:10.668764155 +0000 Birth: -

Please note that i have recreated the token file today with fresh acces tocke about 2H pm

here is the mail.log output abour xoauth2

Apr 15 16:09:38 ostfixrelay sasl-xoauth2: auth failed: Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: Client: created Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: Client::DoStep: called with state 0 Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: Client::InitialStep: TriggerAuthNameCallback err=0 Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: Client::InitialStep: TriggerPasswordCallback err=0 Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: TokenStore::Read: file=/etc/tokens/[username] Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: TokenStore::Read: failed to open file /etc/tokens/[username] Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: Client::DoStep: new state 0 and err -1 Apr 15 16:09:38 ostfixrelay sasl-xoauth2: 2020-04-15 16:09:38: Client: destroyed

I'm on my way to Build from source I post back the result

Kind regards

tarickb commented 4 years ago

Looks like the permissions on the file/directory are not quite right. Can you try chmod 0755 /etc/tokens and chmod 0600 /etc/tokens/[username]?

agrigittest commented 4 years ago

I changed the acces rights according your recommendations but no luck Also this test was made by build from source code lib, note that the error is still the same

stat /etc/tokens/ File: /etc/tokens/ Size: 4096 Blocks: 8 IO Block: 4096 directory Device: fc02h/64514d Inode: 410656 Links: 2 Access: (0755/drwxr-xr-x) Uid: ( 111/ postfix) Gid: ( 114/ postfix) Access: 2020-04-16 15:13:35.903904593 +0000 Modify: 2020-04-16 14:14:51.444630313 +0000 Change: 2020-04-16 15:13:19.627856549 +0000 Birth: -

stat /etc/tokens/[username] File: /etc/tokens/[username] Size: 341 Blocks: 8 IO Block: 4096 regular file Device: fc02h/64514d Inode: 394419 Links: 1 Access: (0600/-rw-------) Uid: ( 111/ postfix) Gid: ( 114/ postfix) Access: 2020-04-16 14:14:51.444630313 +0000 Modify: 2020-04-16 14:14:51.444630313 +0000 Change: 2020-04-16 15:13:36.707906952 +0000 Birth: -

Apr 16 15:14:26 ostfixrelay sasl-xoauth2: auth failed: Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: Client: created Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: Client::DoStep: called with state 0 Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: Client::InitialStep: TriggerAuthNameCallback err=0 Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: Client::InitialStep: TriggerPasswordCallback err=0 Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: TokenStore::Read: file=/etc/tokens/[username] Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: TokenStore::Read: failed to open file /etc/tokens/[username] Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: Client::DoStep: new state 0 and err -1 Apr 16 15:14:26 ostfixrelay sasl-xoauth2: 2020-04-16 15:14:26: Client: destroyed

Here is the content of sasl_passwd file

[smtp.gmail.com]:587 myuser@domain.fr:/etc/tokens/[username]

Here is the token content

{ "access_token" : "ya29.[..]5BE", "expiry" : "0", "refresh_token" : "1//03trfn[...]" }

Please note that user names and domain names token etc... is anonymised here but the right information is configured for all filnames/content

tarickb commented 4 years ago

Interesting. Let's try a few different tests:

Change the permission on the directory to 0777 and the file to 0666, which will tell us if Postfix is running as a user other than postfix (unlikely, I guess).
Repeat the experiment with /var/spool/postfix/etc/tokens, but with 0777/0666 permissions, in case chroot is enabled somewhere that's not obvious.
Since you're building from source, apply this patch and maybe we can get a more useful error message. Unzip and then, in the top-level source directory: patch -p1 < errno.patch

agrigittest commented 4 years ago

/etc/tokens/[username] access rights 0777 0666

drwxrwxrwx 2 postfix postfix 4096 avril 16 17:29 tokens -rw-rw-rw- 1 postfix postfix 341 avril 16 16:14 [username]

Mail log output : Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: Client: created Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: Client::DoStep: called with state 0 Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: Client::InitialStep: TriggerAuthNameCallback err=0 Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: Client::InitialStep: TriggerPasswordCallback err=0 Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: TokenStore::Read: file=/etc/tokens/[username] Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: TokenStore::Read: failed to open file /etc/tokens/[username] Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: Client::DoStep: new state 0 and err -1 Apr 16 18:15:58 ostfixrelay sasl-xoauth2: 2020-04-16 18:15:58: Client: destroyed

/var/spool/postfix/etc/tokens/[username] access rights 0777 0666 drwxrwxrwx 2 postfix postfix 4096 avril 16 18:24 tokens -rw-rw-rw- 1 postfix postfix 342 avril 16 18:24 [username]

/etc/postfix/sasl/sasl_passwd file was changed according new location [smtp.gmail.com]:587 myuser@mydomain.fr:/var/spool/postfix/etc/tokens/[username]

Maillog output :

Apr 16 18:27:49 ostfixrelay sasl-xoauth2: auth failed: Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: Client: created Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: Client::DoStep: called with state 0 Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: Client::InitialStep: TriggerAuthNameCallback err=0 Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: Client::InitialStep: TriggerPasswordCallback err=0 Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: TokenStore::Read: file=/var/spool/postfix/etc/tokens/[username] Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: TokenStore::Read: failed to open file /var/spool/postfix/etc/tokens/[username] Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: Client::DoStep: new state 0 and err -1 Apr 16 18:27:49 ostfixrelay sasl-xoauth2: 2020-04-16 18:27:49: Client: destroyed

Patched version patch -p1 < errno.patch patching file src/token_store.cc

File permission not changed from test 2

mailog output :

Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: Client: created Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: Client::DoStep: called with state 0 Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: Client::InitialStep: TriggerAuthNameCallback err=0 Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: Client::InitialStep: TriggerPasswordCallback err=0 Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: TokenStore::Read: file=/var/spool/postfix/etc/tokens/[username] Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: TokenStore::Read: failed to open file /var/spool/postfix/etc/tokens/[username]: No such file or directory Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: Client::DoStep: new state 0 and err -1 Apr 16 18:50:33 ostfixrelay sasl-xoauth2: 2020-04-16 18:50:33: Client: destroyed

The log output show that the token file does not exists at least that is what sasl-xoauth2 get as return

stat /var/spool/postfix/etc/tokens/[username] File: /var/spool/postfix/etc/tokens/[username] Size: 342 Blocks: 8 IO Block: 4096 regular file Device: fc02h/64514d Inode: 281032 Links: 1 Access: (0666/-rw-rw-rw-) Uid: ( 111/ postfix) Gid: ( 114/ postfix) Access: 2020-04-16 18:24:14.402755620 +0200 Modify: 2020-04-16 18:24:14.402755620 +0200 Change: 2020-04-16 18:26:59.847193479 +0200 Birth: -

sasl-xoauth runs under posfix user right ?

here are the processe runned by postfix user 👍 ps -u postfix PID TTY TIME CMD 2721 ? 00:00:00 pickup 2722 ? 00:00:00 qmgr 2726 ? 00:00:00 tlsmgr

also see htop output for posfix user posfix_user_process

tarickb commented 4 years ago

For test #2, the path in /etc/postfix/sasl/sasl_passwd should still be /etc/tokens/[username], but the file itself will be in /var/spool/postfix/etc/tokens/[username]. Can you repeat that test?

And yes, it does look like you're running as postfix.

agrigittest commented 4 years ago

It look like you hit right !

Apr 16 19:42:18 ostfixrelay postfix/smtpd[3048]: connect from my-computer.mydomain.fr[192.168.1.41] Apr 16 19:42:18 ostfixrelay postfix/smtpd[3048]: D0D912733: client=smy-computer.mydomain.fr[192.168.1.41] Apr 16 19:42:18 ostfixrelay postfix/cleanup[3051]: D0D912733: message-id=027201d61416$60098140$201c83c0$@mydomain.fr Apr 16 19:42:18 ostfixrelay postfix/qmgr[3017]: D0D912733: from=my.user@mydomain.fr, size=2926, nrcpt=1 (queue active) Apr 16 19:42:20 ostfixrelay postfix/smtp[3052]: D0D912733: to=my.user@mydomain.fr, relay=smtp.gmail.com[64.233.167.108]:587, delay=1.4, delays=0.13/0.04/0.39/0.81, dsn=2.0.0, status=sent (250 2.0.0 OK 1587058940 j124sm4476734wmb.25 - gsmtp) Apr 16 19:42:20 ostfixrelay postfix/qmgr[3017]: D0D912733: removed Apr 16 19:42:21 ostfixrelay postfix/smtpd[3048]: disconnect from smy-computer.mydomain.fr[192.168.1.41] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5

Note this is a fresh installed test server on Ubuntu 18.4 LTS with posfix installed with default options and configured as relay server.

Here is what i get from process investigations

ps aux | grep postfix root 3014 0.0 0.3 67376 3584 ? Ss 19:39 0:00 /usr/lib/postfix/sbin/master -w postfix 3016 0.0 0.4 73812 4688 ? S 19:39 0:00 pickup -l -t unix -u -c postfix 3017 0.0 0.4 73860 4820 ? S 19:39 0:00 qmgr -l -t unix -u postfix 3038 0.0 0.7 87724 7732 ? S 19:39 0:00 tlsmgr -l -t unix -u -c root 3074 0.0 0.1 13136 1088 pts/1 S+ 19:50 0:00 grep --color=auto postfix

check the root of eatch process :

ls -ld /proc/3014/root lrwxrwxrwx 1 root root 0 avril 16 19:50 /proc/3014/root -> / ls -ld /proc/3016/root lrwxrwxrwx 1 root root 0 avril 16 19:54 /proc/3016/root -> /var/spool/postfix ls -ld /proc/3017/root lrwxrwxrwx 1 root root 0 avril 16 19:57 /proc/3017/root -> / ls -ld /proc/3038/root lrwxrwxrwx 1 root root 0 avril 16 19:58 /proc/3038/root -> /var/spool/postfix

from here we can find out that pickup process and tlsmgr have set their root dir to /var/spool/postfix

So i suppose that this must be default location as i did not setup chroot env for this server

Finally it looks like my error was that i modified the path in sasl_passwd file for the /var/spool/postfix test i made here and befor.

Any way i thak you so much for your kind help. It is about days that i try to get Oauth2 mechanisme to work with Exim4 or Postfix, tried different solutions from various authors this was my last take befor i start my own script as i was able to get anything work with Curl. But lest say that a full Bash solution was more like a workaround in my sense.

So once again thanks for your greate work and help, I will set up a new server from scratsh again with the stable ubuntu package in order to document a bit more the setup now that it works.

Kind regards from France

tarickb commented 4 years ago

Excellent! I'm glad it worked. I'll leave this issue open for now so I can remember to update the documentation and clarify where the token file should go if chroot is enabled.

tarickb commented 4 years ago

Updated the README in https://github.com/tarickb/sasl-xoauth2/commit/37786f8be4517e71177bb85208cd23bca5b486f9.

tarickb / sasl-xoauth2

Clarify README to describe where token file goes, and what goes into sasl_passwd, if chroot is enabled #3