Correction. Mail crypt works fine when I'm logged with the regular password authentication but doesn't when OAUTH2 is used. Max Kostikov ?????(?) 2022-01-31 12:30:> Yes, that's right. > I tried to get key with userdb before I wrote in the Dovecot list but > this doesn't work for me. > Yes, the decryption key is correct but for some reason it doesn't > applied when key decryption. > > > Aki Tuomi ?????(?) 2022-01-31 12:09: >> In fact now that I looked through your configs one more, this is >> already what you are doing, except you are exporting the private key >> password in three different places. >> >> So basically, if you do `doveadm user foobar` it should already give >> you a correct key. >> >> You can see if the key is correct with `doveadm mailbox cryptokey >> export -u user -U` >> >> Aki >> >>> On 31/01/2022 12:03 Aki Tuomi <aki.tuomi at open-xchange.com> wrote: >>> >>> >>> Hgm. You have userdb lookups enabled, why not just move the entire >>> mail_crypt_private_password handling there instead of passdb? This >>> way it'll work with LMTP/LDA as well. >>> >>> So move all user related fields to the userdb lookup, and keep only >>> the authentication handling in passdb. >>> >>> In your configuration, passdb lookups are not done for LMTP/LDA etc. >>> >>> Aki >>> >>> > On 31/01/2022 12:00 Max Kostikov <max at kostikov.co> wrote: >>> > >>> > >>> > Unfortunately there are no "master out" entries in the log, but I have >>> > "userdb out" >>> > >>> > Jan 31 09:56:40 example.com dovecot: auth: Debug: master userdb out: >>> > USER#0111609564161#011max.kostikov at gmail.com#011home=/var/vmail/gmail.com/max.kostikov/#011mail=maildir:/var/vmail/gmail.com/max.kostikov/#011uid=150#011gid=8#011quota=dirsize:storage=0#011userdb_mail_crypt_private_password=<hidden>#011auth_mech=XOAUTH2#011auth_token=a8a38b3119780448ae96debd5687df75f5043378 >>> > >>> > >>> > Aki Tuomi ?????(?) 2022-01-31 11:47: >>> > > Was the field present in auth debug logs, it should be shown in the >>> > > "master out" log line and also it should be visible on mail_debug=yes >>> > > logs as `plugin/mail_crypt_private_key_password`. >>> > > >>> > > Aki >>> > > >>> > >> On 31/01/2022 11:40 Max Kostikov <max at kostikov.co> wrote: >>> > >> >>> > >> >>> > >> Unfortunatelly I still get decryption error with "Password not >>> > >> available" >>> > >> >>> > >> ... >>> > >> Jan 31 09:39:03 dev-message-portal-08.healthycareservice.com dovecot: >>> > >> imap(max.kostikov at gmail.com)<22267><59cRjt3Wbtx/AAAB>: Error: Mailbox >>> > >> INBOX: UID=1: read() failed: >>> > >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.dev-message-portal-08.healthycareservice.com,S=2140,W=2193:2,S) >>> > >> failed: Private key not available: Cannot decrypt key >>> > >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: >>> > >> Cannot >>> > >> decrypt key >>> > >> 98ae0f998f9139ebe20a97de77f162dcdeed496e38c9b5910186f999f3ef66c8: >>> > >> Password not available >>> > >> Jan 31 09:39:03 dev-message-portal-08.healthycareservice.com dovecot: >>> > >> imap(max.kostikov at gmail.com)<22267><59cRjt3Wbtx/AAAB>: Disconnected: >>> > >> FETCH failed: Mailbox INBOX: UID=1: read() failed: >>> > >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.dev-message-portal-08.healthycareservice.com,S=2140,W=2193:2,S) >>> > >> failed: Private key not available: Cannot decrypt key >>> > >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: >>> > >> Cannot >>> > >> decrypt key >>> > >> 98ae0f998f9139ebe20a97de77f162dcdeed496e38c9b5910186f999f3ef66c8: >>> > >> Password not available in=463 out=1872 deleted=0 expunged=0 trashed=0 >>> > >> hdr_count=1 hdr_bytes=115 body_count=0 body_bytes=0 >>> > >> >>> > >> >>> > >> Aki Tuomi ?????(?) 2022-01-31 11:33: >>> > >> > try adding >>> > >> > >>> > >> > result_success = continue-ok >>> > >> > >>> > >> > to the oauth2 database. >>> > >> > >>> > >> > Aki >>> > >> > >>> > >> >> On 31/01/2022 11:27 Max Kostikov <max at kostikov.co> wrote: >>> > >> >> >>> > >> >> >>> > >> >> Aki, thanks for your hint. >>> > >> >> Unfortunatelly I can't get this work. >>> > >> >> Here is my configuration. >>> > >> >> >>> > >> >> auth_mechanisms = $auth_mechanisms oauthbearer xoauth2 >>> > >> >> passdb { >>> > >> >> driver = oauth2 >>> > >> >> mechanisms = xoauth2 oauthbearer >>> > >> >> args = /etc/dovecot/dovecot-oauth2.conf.ext >>> > >> >> } >>> > >> >> passdb { >>> > >> >> driver = sql >>> > >> >> skip = unauthenticated >>> > >> >> args = /etc/dovecot/dovecot-sql-encryption.conf.ext >>> > >> >> } >>> > >> >> passdb { >>> > >> >> skip = authenticated >>> > >> >> driver = sql >>> > >> >> args = /etc/dovecot/dovecot-sql.conf.ext >>> > >> >> } >>> > >> >> userdb { >>> > >> >> driver = sql >>> > >> >> args = /etc/dovecot/dovecot-sql.conf.ext >>> > >> >> } >>> > >> >> >>> > >> >> * In the dovecot-oauth2.conf.ext I have typical Google configuration. >>> > >> >> >>> > >> >> * dovecot-sql-encryption.conf.ext contains only SQL query for >>> > >> >> password: >>> > >> >> >>> > >> >> password_query = \ >>> > >> >> SELECT \ >>> > >> >> 150 AS userdb_uid, 8 AS userdb_gid, \ >>> > >> >> SHA2(CONCAT(username, random_key), 256) AS >>> > >> >> userdb_mail_crypt_private_password, \ >>> > >> >> 'Y' AS noauthenticate \ >>> > >> >> FROM mailbox WHERE username = '%u' >>> > >> >> >>> > >> >> * dovecot-sql.conf.ext contains normal password authentication >>> > >> >> queries: >>> > >> >> >>> > >> >> password_query = \ >>> > >> >> SELECT username AS user, password, \ >>> > >> >> 150 AS userdb_uid, 8 AS userdb_gid, \ >>> > >> >> SHA2(CONCAT(username, random_key), 256) AS >>> > >> >> userdb_mail_crypt_private_password \ >>> > >> >> FROM mailbox WHERE username = '%u' >>> > >> >> AND active = '1' >>> > >> >> >>> > >> >> user_query = \ >>> > >> >> SELECT \ >>> > >> >> CONCAT('/var/vmail/', LCASE(maildir)) AS home, \ >>> > >> >> CONCAT('maildir:/var/vmail/', LCASE(maildir)) AS mail, \ >>> > >> >> 150 AS uid, 8 AS gid, concat('dirsize:storage=', quota) AS quota, \ >>> > >> >> SHA2(CONCAT(username, random_key), 256) AS >>> > >> >> userdb_mail_crypt_private_password \ >>> > >> >> FROM mailbox WHERE username = '%u' >>> > >> >> AND active = '1' >>> > >> >> >>> > >> >> iterate_query = \ >>> > >> >> SELECT username AS user FROM mailbox >>> > >> >> >>> > >> >> It seems now dovecot-sql-encryption.conf.ext is not invoked >>> > >> >> >>> > >> >> Jan 31 09:11:45 example.com dovecot: imap-login: Login: >>> > >> >> user=<max.kostikov at gmail.com>, method=XOAUTH2, rip=127.0.0.1, >>> > >> >> lip=127.0.0.1, mpid=22615, TLS, session=<XtdzLN3WnMl/AAAB> >>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: client in: >>> > >> >> AUTH#0111#011XOAUTH2#011service=imap#011secured=tls#011session=56F7LN3Wnsl/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=51614#011local_name=example.com#011resp=<hidden> >>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Performing passdb >>> > >> >> lookup >>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Making token >>> > >> >> validation lookup to >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token>>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> queue >>> > >> >> https://www.googleapis.com:443: Using existing connection to >>> > >> >> 172.253.63.95:443 (SSL=www.googleapis.com) (1 requests pending) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: >>> > >> >> Submitted (requests left=1) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer >>> > >> >> 172.253.63.95:443: Using 1 idle connections to handle 1 requests (1 >>> > >> >> total connections ready) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> queue >>> > >> >> https://www.googleapis.com:443: Connection to peer 172.253.63.95:443 >>> > >> >> claimed request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI] >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn >>> > >> >> 172.253.63.95:443 [1]: Claimed request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI] >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: >>> > >> >> Sent header >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer >>> > >> >> 172.253.63.95:443: No more requests to service for this peer (1 >>> > >> >> connections exist, 0 pending) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn >>> > >> >> 172.253.63.95:443 [1]: Got 200 response for request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: >>> > >> >> OK (took 20 ms + 0 ms in queue) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Token validation >>> > >> >> succeeded >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> azp >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> aud >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> sub >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> scope >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> exp >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> expires_in >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> email >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> email_verified >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> access_type >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Making >>> > >> >> introspection >>> > >> >> request to https://www.googleapis.com/oauth2/v2/userinfo >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> queue >>> > >> >> https://www.googleapis.com:443: Using existing connection to >>> > >> >> 172.253.63.95:443 (SSL=www.googleapis.com) (1 requests pending) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: >>> > >> >> Submitted (requests left=2) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn >>> > >> >> 172.253.63.95:443 [1]: Response payload stream destroyed (0 ms after >>> > >> >> initial response) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: >>> > >> >> Finished >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> queue >>> > >> >> https://www.googleapis.com:443: Dropping request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI] >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req9: GET >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: >>> > >> >> Free (requests left=2) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer >>> > >> >> 172.253.63.95:443: Using 1 idle connections to handle 1 requests (1 >>> > >> >> total connections ready) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> queue >>> > >> >> https://www.googleapis.com:443: Connection to peer 172.253.63.95:443 >>> > >> >> claimed request [Req10: GET >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo] >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn >>> > >> >> 172.253.63.95:443 [1]: Claimed request [Req10: GET >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo] >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: >>> > >> >> Sent >>> > >> >> header >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer >>> > >> >> 172.253.63.95:443: No more requests to service for this peer (1 >>> > >> >> connections exist, 0 pending) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn >>> > >> >> 172.253.63.95:443 [1]: Got 200 response for request [Req10: GET >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo]: OK (took 57 ms + 0 ms >>> > >> >> in >>> > >> >> queue) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Introspection >>> > >> >> succeeded >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> id >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> email >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> verified_email >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> name >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> given_name >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> family_name >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> picture >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field >>> > >> >> locale >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Finished passdb >>> > >> >> lookup >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> auth(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Auth request >>> > >> >> finished >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: client passdb out: >>> > >> >> OK#0111#011user=foo at gmail.com#011token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn >>> > >> >> 172.253.63.95:443 [1]: Response payload stream destroyed (0 ms after >>> > >> >> initial response) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: >>> > >> >> Finished >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> queue >>> > >> >> https://www.googleapis.com:443: Dropping request [Req10: GET >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo] >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: host >>> > >> >> www.googleapis.com: Host is idle (timeout = 1786062 msecs) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: >>> > >> >> Free >>> > >> >> (requests left=1) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer >>> > >> >> 172.253.63.95:443: No requests to service for this peer (1 connections >>> > >> >> exist, 0 pending) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn >>> > >> >> 172.253.63.95:443 [1]: No more requests queued; going idle (timeout >>> > >> >> 60000 msecs) >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: master in: >>> > >> >> REQUEST#0113880255489#01122604#0111#0117acd1216a7041ddbdf7b563a2bc10dd1#011session_pid=22629#011request_auth_token >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Performing userdb >>> > >> >> lookup >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: Handling USER >>> > >> >> request >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Performing userdb >>> > >> >> lookup >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): SELECT >>> > >> >> CONCAT('/var/vmail/', LCASE(maildir)) AS home, >>> > >> >> CONCAT('maildir:/var/vmail/', LCASE(maildir)) AS mail, 150 AS uid, 8 >>> > >> >> AS >>> > >> >> gid, concat('dirsize:storage=', quota) AS quota, SHA2(CONCAT(username, >>> > >> >> random_key), 256) AS userdb_mail_crypt_private_password FROM mailbox >>> > >> >> WHERE username = 'foo at gmail.com' >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: >>> > >> >> mysql(localhost): Finished query 'SELECT CONCAT('/var/vmail/', >>> > >> >> LCASE(maildir)) AS home, CONCAT('maildir:/var/vmail/', LCASE(maildir)) >>> > >> >> AS mail, 150 AS uid, 8 AS gid, concat('dirsize:storage=', quota) AS >>> > >> >> quota, SHA2(CONCAT(username, random_key), 256) AS >>> > >> >> userdb_mail_crypt_private_password FROM mailbox WHERE username >>> > >> >> 'foo at gmail.com'' in 8 msecs >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Finished userdb >>> > >> >> lookup >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: Finished >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Finished userdb >>> > >> >> lookup >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: master userdb out: >>> > >> >> USER#0113880255489#011foo at gmail.com#011home=/var/vmail/gmail.com/max.kostikov/#011mail=maildir:/var/vmail/gmail.com/max.kostikov/#011uid=150#011gid=8#011quota=dirsize:storage=0#011userdb_mail_crypt_private_password=<hidden>#011auth_mech=XOAUTH2#011auth_token=cd1adb77645bc681e152d945b5617ef602b29fb7 >>> > >> >> Jan 31 09:11:46 example.com dovecot: imap-login: Login: >>> > >> >> user=<foo at gmail.com>, method=XOAUTH2, rip=127.0.0.1, lip=127.0.0.1, >>> > >> >> mpid=22629, TLS, session=<56F7LN3Wnsl/AAAB> >>> > >> >> Jan 31 09:11:46 example.com dovecot: >>> > >> >> imap(foo at gmail.com)<22615><XtdzLN3WnMl/AAAB>: Error: Mailbox INBOX: >>> > >> >> UID=1: read() failed: >>> > >> >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.example.com,S=2140,W=2193:2,S) >>> > >> >> failed: Private key not available: Cannot decrypt key >>> > >> >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: >>> > >> >> Cannot >>> > >> >> decrypt key >>> > >> >> 98ae0f998f9139ebe20a97de77f162dcdeed496e38c9b5910186f999f3ef66c8: >>> > >> >> Password not available (FETCH BODY[HEADER]) >>> > >> >> Jan 31 09:11:46 example.com dovecot: >>> > >> >> imap(foo at gmail.com)<22615><XtdzLN3WnMl/AAAB>: Disconnected: FETCH >>> > >> >> read() >>> > >> >> failed in=57 out=800 deleted=0 expunged=0 trashed=0 hdr_count=1 >>> > >> >> hdr_bytes=0 body_count=0 body_bytes=0 >>> > >> >> >>> > >> >> I've tried to add >>> > >> >> >>> > >> >> pass_attrs >>> > >> >> userdb_mail_crypt_private_password=%{userdb:userdb_mail_crypt_private_password} >>> > >> >> >>> > >> >> into the pass_attrs >>> > >> >> userdb_mail_crypt_private_password=%{userdb:mail_crypt_private_password} >>> > >> >> but it looks like no correct key decrypt password passed >>> > >> >> >>> > >> >> ... >>> > >> >> Jan 31 09:10:49 example.com dovecot: >>> > >> >> imap(foo at gmail.com)<20613><HVcHKd3W9sh/AAAB>: Error: Mailbox INBOX: >>> > >> >> UID=1: read() failed: >>> > >> >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.example.com,S=2140,W=2193:2,S) >>> > >> >> failed: Private key not available: Cannot decrypt key >>> > >> >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: >>> > >> >> error:03070068:bignum routines:BN_mpi2bn:encoding error (FETCH >>> > >> >> BODY[HEADER]) >>> > >> >> Jan 31 09:10:50 example.com dovecot: >>> > >> >> imap(foo at gmail.com)<20631><cuIWKd3W+Mh/AAAB>: Error: Mailbox INBOX: >>> > >> >> UID=1: read() failed: >>> > >> >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.example.com,S=2140,W=2193:2,S) >>> > >> >> failed: Private key not available: Cannot decrypt key >>> > >> >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: >>> > >> >> error:03070068:bignum routines:BN_mpi2bn:encoding error >>> > >> >> >>> > >> >> >>> > >> >> Aki Tuomi ?????(?) 2022-01-31 08:34: >>> > >> >> >> On 28/01/2022 21:27 Max Kostikov <max at kostikov.co> wrote: >>> > >> >> >> >>> > >> >> >> >>> > >> >> >> We currently use Dovecot and mailbox encryption via the >>> > >> >> >> mail-crypt-plugin. >>> > >> >> >> With standard password authentication, we set the value of the >>> > >> >> >> individual >>> > >> >> >> password to encrypt the contents of the >>> > >> >> >> userdb_mail_crypt_private_password >>> > >> >> >> mailbox in the SQL query. >>> > >> >> >> Is it possible to set the userdb_mail_crypt_private_password value >>> > >> >> >> when >>> > >> >> >> authenticating via OAUTH2 ? >>> > >> >> >> >>> > >> >> >> -- >>> > >> >> >> Best regards, >>> > >> >> >> Max Kostikov >>> > >> >> > >>> > >> >> > You probably want to split your passdb drivers into two, one which >>> > >> >> > does the authentication and second which populates the private >>> > >> >> > password value. This way it should work correctly on both cases. >>> > >> >> > >>> > >> >> > passdb { >>> > >> >> > driver = sql >>> > >> >> > skip = unauthenticated >>> > >> >> > ... >>> > >> >> > } >>> > >> >> > >>> > >> >> > and ensure your return in this sql query `'Y' as noauthenticate'` >>> > >> >> > >>> > >> >> > Aki >>> > >> >> >>> > >> >> -- >>> > >> >> Best regards, >>> > >> >> Max Kostikov >>> > >> >> >>> > >> >> W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000 >>> > >> >>> > >> -- >>> > >> Best regards, >>> > >> Max Kostikov >>> > >> >>> > >> W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000 >>> > >>> > -- >>> > Best regards, >>> > Max Kostikov >>> > >>> > W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000-- Best regards, Max Kostikov W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000
Using oauth2 or not should make no difference if the key is loaded in userdb. Can you check with mail_debug=yes to see that it gets loaded even if you remove it from passdb sql? Aki> On 31/01/2022 12:41 Max Kostikov <max at kostikov.co> wrote: > > > Correction. Mail crypt works fine when I'm logged with the regular > password authentication > but doesn't when OAUTH2 is used. > > Max Kostikov ?????(?) 2022-01-31 12:30: > > Yes, that's right. > > I tried to get key with userdb before I wrote in the Dovecot list but > > this doesn't work for me. > > Yes, the decryption key is correct but for some reason it doesn't > > applied when key decryption. > > > > > > Aki Tuomi ?????(?) 2022-01-31 12:09: > >> In fact now that I looked through your configs one more, this is > >> already what you are doing, except you are exporting the private key > >> password in three different places. > >> > >> So basically, if you do `doveadm user foobar` it should already give > >> you a correct key. > >> > >> You can see if the key is correct with `doveadm mailbox cryptokey > >> export -u user -U` > >> > >> Aki > >> > >>> On 31/01/2022 12:03 Aki Tuomi <aki.tuomi at open-xchange.com> wrote: > >>> > >>> > >>> Hgm. You have userdb lookups enabled, why not just move the entire > >>> mail_crypt_private_password handling there instead of passdb? This > >>> way it'll work with LMTP/LDA as well. > >>> > >>> So move all user related fields to the userdb lookup, and keep only > >>> the authentication handling in passdb. > >>> > >>> In your configuration, passdb lookups are not done for LMTP/LDA etc. > >>> > >>> Aki > >>> > >>> > On 31/01/2022 12:00 Max Kostikov <max at kostikov.co> wrote: > >>> > > >>> > > >>> > Unfortunately there are no "master out" entries in the log, but I have > >>> > "userdb out" > >>> > > >>> > Jan 31 09:56:40 example.com dovecot: auth: Debug: master userdb out: > >>> > USER#0111609564161#011max.kostikov at gmail.com#011home=/var/vmail/gmail.com/max.kostikov/#011mail=maildir:/var/vmail/gmail.com/max.kostikov/#011uid=150#011gid=8#011quota=dirsize:storage=0#011userdb_mail_crypt_private_password=<hidden>#011auth_mech=XOAUTH2#011auth_token=a8a38b3119780448ae96debd5687df75f5043378 > >>> > > >>> > > >>> > Aki Tuomi ?????(?) 2022-01-31 11:47: > >>> > > Was the field present in auth debug logs, it should be shown in the > >>> > > "master out" log line and also it should be visible on mail_debug=yes > >>> > > logs as `plugin/mail_crypt_private_key_password`. > >>> > > > >>> > > Aki > >>> > > > >>> > >> On 31/01/2022 11:40 Max Kostikov <max at kostikov.co> wrote: > >>> > >> > >>> > >> > >>> > >> Unfortunatelly I still get decryption error with "Password not > >>> > >> available" > >>> > >> > >>> > >> ... > >>> > >> Jan 31 09:39:03 dev-message-portal-08.healthycareservice.com dovecot: > >>> > >> imap(max.kostikov at gmail.com)<22267><59cRjt3Wbtx/AAAB>: Error: Mailbox > >>> > >> INBOX: UID=1: read() failed: > >>> > >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.dev-message-portal-08.healthycareservice.com,S=2140,W=2193:2,S) > >>> > >> failed: Private key not available: Cannot decrypt key > >>> > >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: > >>> > >> Cannot > >>> > >> decrypt key > >>> > >> 98ae0f998f9139ebe20a97de77f162dcdeed496e38c9b5910186f999f3ef66c8: > >>> > >> Password not available > >>> > >> Jan 31 09:39:03 dev-message-portal-08.healthycareservice.com dovecot: > >>> > >> imap(max.kostikov at gmail.com)<22267><59cRjt3Wbtx/AAAB>: Disconnected: > >>> > >> FETCH failed: Mailbox INBOX: UID=1: read() failed: > >>> > >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.dev-message-portal-08.healthycareservice.com,S=2140,W=2193:2,S) > >>> > >> failed: Private key not available: Cannot decrypt key > >>> > >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: > >>> > >> Cannot > >>> > >> decrypt key > >>> > >> 98ae0f998f9139ebe20a97de77f162dcdeed496e38c9b5910186f999f3ef66c8: > >>> > >> Password not available in=463 out=1872 deleted=0 expunged=0 trashed=0 > >>> > >> hdr_count=1 hdr_bytes=115 body_count=0 body_bytes=0 > >>> > >> > >>> > >> > >>> > >> Aki Tuomi ?????(?) 2022-01-31 11:33: > >>> > >> > try adding > >>> > >> > > >>> > >> > result_success = continue-ok > >>> > >> > > >>> > >> > to the oauth2 database. > >>> > >> > > >>> > >> > Aki > >>> > >> > > >>> > >> >> On 31/01/2022 11:27 Max Kostikov <max at kostikov.co> wrote: > >>> > >> >> > >>> > >> >> > >>> > >> >> Aki, thanks for your hint. > >>> > >> >> Unfortunatelly I can't get this work. > >>> > >> >> Here is my configuration. > >>> > >> >> > >>> > >> >> auth_mechanisms = $auth_mechanisms oauthbearer xoauth2 > >>> > >> >> passdb { > >>> > >> >> driver = oauth2 > >>> > >> >> mechanisms = xoauth2 oauthbearer > >>> > >> >> args = /etc/dovecot/dovecot-oauth2.conf.ext > >>> > >> >> } > >>> > >> >> passdb { > >>> > >> >> driver = sql > >>> > >> >> skip = unauthenticated > >>> > >> >> args = /etc/dovecot/dovecot-sql-encryption.conf.ext > >>> > >> >> } > >>> > >> >> passdb { > >>> > >> >> skip = authenticated > >>> > >> >> driver = sql > >>> > >> >> args = /etc/dovecot/dovecot-sql.conf.ext > >>> > >> >> } > >>> > >> >> userdb { > >>> > >> >> driver = sql > >>> > >> >> args = /etc/dovecot/dovecot-sql.conf.ext > >>> > >> >> } > >>> > >> >> > >>> > >> >> * In the dovecot-oauth2.conf.ext I have typical Google configuration. > >>> > >> >> > >>> > >> >> * dovecot-sql-encryption.conf.ext contains only SQL query for > >>> > >> >> password: > >>> > >> >> > >>> > >> >> password_query = \ > >>> > >> >> SELECT \ > >>> > >> >> 150 AS userdb_uid, 8 AS userdb_gid, \ > >>> > >> >> SHA2(CONCAT(username, random_key), 256) AS > >>> > >> >> userdb_mail_crypt_private_password, \ > >>> > >> >> 'Y' AS noauthenticate \ > >>> > >> >> FROM mailbox WHERE username = '%u' > >>> > >> >> > >>> > >> >> * dovecot-sql.conf.ext contains normal password authentication > >>> > >> >> queries: > >>> > >> >> > >>> > >> >> password_query = \ > >>> > >> >> SELECT username AS user, password, \ > >>> > >> >> 150 AS userdb_uid, 8 AS userdb_gid, \ > >>> > >> >> SHA2(CONCAT(username, random_key), 256) AS > >>> > >> >> userdb_mail_crypt_private_password \ > >>> > >> >> FROM mailbox WHERE username = '%u' > >>> > >> >> AND active = '1' > >>> > >> >> > >>> > >> >> user_query = \ > >>> > >> >> SELECT \ > >>> > >> >> CONCAT('/var/vmail/', LCASE(maildir)) AS home, \ > >>> > >> >> CONCAT('maildir:/var/vmail/', LCASE(maildir)) AS mail, \ > >>> > >> >> 150 AS uid, 8 AS gid, concat('dirsize:storage=', quota) AS quota, \ > >>> > >> >> SHA2(CONCAT(username, random_key), 256) AS > >>> > >> >> userdb_mail_crypt_private_password \ > >>> > >> >> FROM mailbox WHERE username = '%u' > >>> > >> >> AND active = '1' > >>> > >> >> > >>> > >> >> iterate_query = \ > >>> > >> >> SELECT username AS user FROM mailbox > >>> > >> >> > >>> > >> >> It seems now dovecot-sql-encryption.conf.ext is not invoked > >>> > >> >> > >>> > >> >> Jan 31 09:11:45 example.com dovecot: imap-login: Login: > >>> > >> >> user=<max.kostikov at gmail.com>, method=XOAUTH2, rip=127.0.0.1, > >>> > >> >> lip=127.0.0.1, mpid=22615, TLS, session=<XtdzLN3WnMl/AAAB> > >>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: client in: > >>> > >> >> AUTH#0111#011XOAUTH2#011service=imap#011secured=tls#011session=56F7LN3Wnsl/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=51614#011local_name=example.com#011resp=<hidden> > >>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Performing passdb > >>> > >> >> lookup > >>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Making token > >>> > >> >> validation lookup to > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token> >>> > >> >> Jan 31 09:11:45 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> queue > >>> > >> >> https://www.googleapis.com:443: Using existing connection to > >>> > >> >> 172.253.63.95:443 (SSL=www.googleapis.com) (1 requests pending) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: > >>> > >> >> Submitted (requests left=1) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer > >>> > >> >> 172.253.63.95:443: Using 1 idle connections to handle 1 requests (1 > >>> > >> >> total connections ready) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> queue > >>> > >> >> https://www.googleapis.com:443: Connection to peer 172.253.63.95:443 > >>> > >> >> claimed request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI] > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn > >>> > >> >> 172.253.63.95:443 [1]: Claimed request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI] > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: > >>> > >> >> Sent header > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer > >>> > >> >> 172.253.63.95:443: No more requests to service for this peer (1 > >>> > >> >> connections exist, 0 pending) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn > >>> > >> >> 172.253.63.95:443 [1]: Got 200 response for request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: > >>> > >> >> OK (took 20 ms + 0 ms in queue) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Token validation > >>> > >> >> succeeded > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> azp > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> aud > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> sub > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> scope > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> exp > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> expires_in > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> email > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> email_verified > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> access_type > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Making > >>> > >> >> introspection > >>> > >> >> request to https://www.googleapis.com/oauth2/v2/userinfo > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> queue > >>> > >> >> https://www.googleapis.com:443: Using existing connection to > >>> > >> >> 172.253.63.95:443 (SSL=www.googleapis.com) (1 requests pending) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: > >>> > >> >> Submitted (requests left=2) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn > >>> > >> >> 172.253.63.95:443 [1]: Response payload stream destroyed (0 ms after > >>> > >> >> initial response) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: > >>> > >> >> Finished > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> queue > >>> > >> >> https://www.googleapis.com:443: Dropping request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI] > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req9: GET > >>> > >> >> https://www.googleapis.com/oauth2/v3/tokeninfo?access_token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI]: > >>> > >> >> Free (requests left=2) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer > >>> > >> >> 172.253.63.95:443: Using 1 idle connections to handle 1 requests (1 > >>> > >> >> total connections ready) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> queue > >>> > >> >> https://www.googleapis.com:443: Connection to peer 172.253.63.95:443 > >>> > >> >> claimed request [Req10: GET > >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo] > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn > >>> > >> >> 172.253.63.95:443 [1]: Claimed request [Req10: GET > >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo] > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: > >>> > >> >> Sent > >>> > >> >> header > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer > >>> > >> >> 172.253.63.95:443: No more requests to service for this peer (1 > >>> > >> >> connections exist, 0 pending) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn > >>> > >> >> 172.253.63.95:443 [1]: Got 200 response for request [Req10: GET > >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo]: OK (took 57 ms + 0 ms > >>> > >> >> in > >>> > >> >> queue) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Introspection > >>> > >> >> succeeded > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> id > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> email > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> verified_email > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> name > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> given_name > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> family_name > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> picture > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Processing field > >>> > >> >> locale > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> oauth2(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Finished passdb > >>> > >> >> lookup > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> auth(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Auth request > >>> > >> >> finished > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: client passdb out: > >>> > >> >> OK#0111#011user=foo at gmail.com#011token=ya29.A0ARrdaM_UsPVyxGVJ2aSHPS0D7gnONiuBcEF5CyUwFhnd6nq94c4T1PAWQeUE5IItCIwLb90QpkNLduHD8_vkeka7j6m574SP3gbg114lopTrmPZmHBIpDzaj2w-JqlV0bkFCT7jKqd5UHWXrRIAdqS0ksDCI > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn > >>> > >> >> 172.253.63.95:443 [1]: Response payload stream destroyed (0 ms after > >>> > >> >> initial response) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: > >>> > >> >> Finished > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> queue > >>> > >> >> https://www.googleapis.com:443: Dropping request [Req10: GET > >>> > >> >> https://www.googleapis.com/oauth2/v2/userinfo] > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: host > >>> > >> >> www.googleapis.com: Host is idle (timeout = 1786062 msecs) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: > >>> > >> >> request [Req10: GET https://www.googleapis.com/oauth2/v2/userinfo]: > >>> > >> >> Free > >>> > >> >> (requests left=1) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client[1]: peer > >>> > >> >> 172.253.63.95:443: No requests to service for this peer (1 connections > >>> > >> >> exist, 0 pending) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: http-client: conn > >>> > >> >> 172.253.63.95:443 [1]: No more requests queued; going idle (timeout > >>> > >> >> 60000 msecs) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: master in: > >>> > >> >> REQUEST#0113880255489#01122604#0111#0117acd1216a7041ddbdf7b563a2bc10dd1#011session_pid=22629#011request_auth_token > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Performing userdb > >>> > >> >> lookup > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn > >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: Handling USER > >>> > >> >> request > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn > >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: > >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Performing userdb > >>> > >> >> lookup > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn > >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: > >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): SELECT > >>> > >> >> CONCAT('/var/vmail/', LCASE(maildir)) AS home, > >>> > >> >> CONCAT('maildir:/var/vmail/', LCASE(maildir)) AS mail, 150 AS uid, 8 > >>> > >> >> AS > >>> > >> >> gid, concat('dirsize:storage=', quota) AS quota, SHA2(CONCAT(username, > >>> > >> >> random_key), 256) AS userdb_mail_crypt_private_password FROM mailbox > >>> > >> >> WHERE username = 'foo at gmail.com' > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: > >>> > >> >> mysql(localhost): Finished query 'SELECT CONCAT('/var/vmail/', > >>> > >> >> LCASE(maildir)) AS home, CONCAT('maildir:/var/vmail/', LCASE(maildir)) > >>> > >> >> AS mail, 150 AS uid, 8 AS gid, concat('dirsize:storage=', quota) AS > >>> > >> >> quota, SHA2(CONCAT(username, random_key), 256) AS > >>> > >> >> userdb_mail_crypt_private_password FROM mailbox WHERE username > >>> > >> >> 'foo at gmail.com'' in 8 msecs > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn > >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: > >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Finished userdb > >>> > >> >> lookup > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth-worker(22005): Debug: conn > >>> > >> >> unix:auth-worker (pid=22001,uid=113): auth-worker<19>: Finished > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: > >>> > >> >> sql(foo at gmail.com,127.0.0.1,<56F7LN3Wnsl/AAAB>): Finished userdb > >>> > >> >> lookup > >>> > >> >> Jan 31 09:11:46 example.com dovecot: auth: Debug: master userdb out: > >>> > >> >> USER#0113880255489#011foo at gmail.com#011home=/var/vmail/gmail.com/max.kostikov/#011mail=maildir:/var/vmail/gmail.com/max.kostikov/#011uid=150#011gid=8#011quota=dirsize:storage=0#011userdb_mail_crypt_private_password=<hidden>#011auth_mech=XOAUTH2#011auth_token=cd1adb77645bc681e152d945b5617ef602b29fb7 > >>> > >> >> Jan 31 09:11:46 example.com dovecot: imap-login: Login: > >>> > >> >> user=<foo at gmail.com>, method=XOAUTH2, rip=127.0.0.1, lip=127.0.0.1, > >>> > >> >> mpid=22629, TLS, session=<56F7LN3Wnsl/AAAB> > >>> > >> >> Jan 31 09:11:46 example.com dovecot: > >>> > >> >> imap(foo at gmail.com)<22615><XtdzLN3WnMl/AAAB>: Error: Mailbox INBOX: > >>> > >> >> UID=1: read() failed: > >>> > >> >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.example.com,S=2140,W=2193:2,S) > >>> > >> >> failed: Private key not available: Cannot decrypt key > >>> > >> >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: > >>> > >> >> Cannot > >>> > >> >> decrypt key > >>> > >> >> 98ae0f998f9139ebe20a97de77f162dcdeed496e38c9b5910186f999f3ef66c8: > >>> > >> >> Password not available (FETCH BODY[HEADER]) > >>> > >> >> Jan 31 09:11:46 example.com dovecot: > >>> > >> >> imap(foo at gmail.com)<22615><XtdzLN3WnMl/AAAB>: Disconnected: FETCH > >>> > >> >> read() > >>> > >> >> failed in=57 out=800 deleted=0 expunged=0 trashed=0 hdr_count=1 > >>> > >> >> hdr_bytes=0 body_count=0 body_bytes=0 > >>> > >> >> > >>> > >> >> I've tried to add > >>> > >> >> > >>> > >> >> pass_attrs > >>> > >> >> userdb_mail_crypt_private_password=%{userdb:userdb_mail_crypt_private_password} > >>> > >> >> > >>> > >> >> into the pass_attrs > >>> > >> >> userdb_mail_crypt_private_password=%{userdb:mail_crypt_private_password} > >>> > >> >> but it looks like no correct key decrypt password passed > >>> > >> >> > >>> > >> >> ... > >>> > >> >> Jan 31 09:10:49 example.com dovecot: > >>> > >> >> imap(foo at gmail.com)<20613><HVcHKd3W9sh/AAAB>: Error: Mailbox INBOX: > >>> > >> >> UID=1: read() failed: > >>> > >> >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.example.com,S=2140,W=2193:2,S) > >>> > >> >> failed: Private key not available: Cannot decrypt key > >>> > >> >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: > >>> > >> >> error:03070068:bignum routines:BN_mpi2bn:encoding error (FETCH > >>> > >> >> BODY[HEADER]) > >>> > >> >> Jan 31 09:10:50 example.com dovecot: > >>> > >> >> imap(foo at gmail.com)<20631><cuIWKd3W+Mh/AAAB>: Error: Mailbox INBOX: > >>> > >> >> UID=1: read() failed: > >>> > >> >> read(/var/vmail/gmail.com/max.kostikov/cur/1643481212.M353350P24555.example.com,S=2140,W=2193:2,S) > >>> > >> >> failed: Private key not available: Cannot decrypt key > >>> > >> >> 34255c3a029dc86ba4f07fa9bae2e87e4254de1d582f220a99b46f20bd382870: > >>> > >> >> error:03070068:bignum routines:BN_mpi2bn:encoding error > >>> > >> >> > >>> > >> >> > >>> > >> >> Aki Tuomi ?????(?) 2022-01-31 08:34: > >>> > >> >> >> On 28/01/2022 21:27 Max Kostikov <max at kostikov.co> wrote: > >>> > >> >> >> > >>> > >> >> >> > >>> > >> >> >> We currently use Dovecot and mailbox encryption via the > >>> > >> >> >> mail-crypt-plugin. > >>> > >> >> >> With standard password authentication, we set the value of the > >>> > >> >> >> individual > >>> > >> >> >> password to encrypt the contents of the > >>> > >> >> >> userdb_mail_crypt_private_password > >>> > >> >> >> mailbox in the SQL query. > >>> > >> >> >> Is it possible to set the userdb_mail_crypt_private_password value > >>> > >> >> >> when > >>> > >> >> >> authenticating via OAUTH2 ? > >>> > >> >> >> > >>> > >> >> >> -- > >>> > >> >> >> Best regards, > >>> > >> >> >> Max Kostikov > >>> > >> >> > > >>> > >> >> > You probably want to split your passdb drivers into two, one which > >>> > >> >> > does the authentication and second which populates the private > >>> > >> >> > password value. This way it should work correctly on both cases. > >>> > >> >> > > >>> > >> >> > passdb { > >>> > >> >> > driver = sql > >>> > >> >> > skip = unauthenticated > >>> > >> >> > ... > >>> > >> >> > } > >>> > >> >> > > >>> > >> >> > and ensure your return in this sql query `'Y' as noauthenticate'` > >>> > >> >> > > >>> > >> >> > Aki > >>> > >> >> > >>> > >> >> -- > >>> > >> >> Best regards, > >>> > >> >> Max Kostikov > >>> > >> >> > >>> > >> >> W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000 > >>> > >> > >>> > >> -- > >>> > >> Best regards, > >>> > >> Max Kostikov > >>> > >> > >>> > >> W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000 > >>> > > >>> > -- > >>> > Best regards, > >>> > Max Kostikov > >>> > > >>> > W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000 > > -- > Best regards, > Max Kostikov > > W: https://kostikov.co | E: max at kostikov.co | T: +7(952)7927000