Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Mail delivery fails on CentOS 7.5 #159

Closed
giacomd opened this issue May 30, 2018 · 8 comments
Closed

Mail delivery fails on CentOS 7.5 #159

giacomd opened this issue May 30, 2018 · 8 comments

Comments

@giacomd
Copy link

giacomd commented May 30, 2018

As discussed by mail with @jrse and @dalgaaf, I am experiencing the following problem when running on a CentOS 7.5:

May 30 17:02:01 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884): Error: SSL context initialization failed, disabling SSL: Couldn't parse DH parameters: error:0906D06C:PEM routines:PEM_read_bio:no start line: Expecting: DH PARAMETERS
May 30 17:02:01 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884): Connect from SOURCE_IP_ADDRESS
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884, username): Debug: [START] rbox-storage.cpp: rbox_storage_get_list_settings at line 85
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884, username): Debug: [END] rbox-storage.cpp: rbox_storage_get_list_settings at line 98
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884, username): Debug: [START] rbox-storage.cpp: rbox_storage_alloc at line 62
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884, username): Debug: [END] rbox-storage.cpp: rbox_storage_alloc at line 79
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884, username): Debug: [START] rbox-storage.cpp: rbox_storage_create at line 155
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(43884, username): Debug: [END] rbox-storage.cpp: rbox_storage_create at line 163
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: rbox_mailbox_alloc at line 213
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: read_plugin_configuration at line 343
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: read_plugin_configuration at line 359
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: rbox_mailbox_alloc at line 245
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: rbox_mailbox_open at line 560
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: rbox_mailbox_alloc_index at line 250
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: rbox_mailbox_alloc_index at line 266
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: rbox_open_mailbox at line 305
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: rbox_open_mailbox at line 338
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: rbox_read_header at line 271
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: rbox_read_header at line 300
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: rbox_mailbox_open at line 593
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-save.cpp: rbox_save_alloc at line 53
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-save.cpp: rbox_save_alloc at line 76
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-mail.cpp: rbox_mail_alloc at line 91
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-mail.cpp: rbox_mail_alloc at line 101
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: rbox_mailbox_get_metadata at line 731
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: rbox_mailbox_get_metadata at line 749
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-copy.cpp: rbox_mail_copy at line 42
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-copy.cpp: rbox_mail_storage_copy at line 259
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: rbox_open_rados_connection at line 370
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [START] rbox-storage.cpp: read_plugin_configuration at line 343
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Debug: [END] rbox-storage.cpp: read_plugin_configuration at line 359
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error: /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.5/rpm/el7/BUILD/ceph-12.2.5/src/common/ceph_crypto.cc: In function 'void ceph::crypto::init(CephContext*)' thread 7f7d99cac740 time 2018-05-30 17:02:02.148625
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error: /home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.2.5/rpm/el7/BUILD/ceph-12.2.5/src/common/ceph_crypto.cc: 71: FAILED assert(crypto_context != __null)
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  ceph version 12.2.5 (cad919881333ac92274171586c827e01f554a70a) luminous (stable)
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x110) [0x7f7d8ceb3d50]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  2: (ceph::crypto::init(CephContext*)+0x106) [0x7f7d8d1b1066]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  3: (CephContext::init_crypto()+0x15) [0x7f7d8d0ee3e5]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  4: (common_init_finish(CephContext*)+0x2c) [0x7f7d8d0ea5ec]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  5: (librados::RadosClient::connect()+0x30) [0x7f7d96199390]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  6: (librmb::RadosClusterImpl::connect()+0x2f) [0x7f7d966688df]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  7: (librmb::RadosClusterImpl::io_ctx_create(std::string const&, librados::IoCtx*)+0x24) [0x7f7d96668924]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  8: (librmb::RadosStorageImpl::create_connection(std::string const&)+0x32) [0x7f7d96669a62]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  9: (rbox_open_rados_connection()+0x3e6) [0x7f7d968a98c6]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  10: (rbox_mail_storage_copy(mail_save_context*, mail*)+0x92) [0x7f7d9689b512]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  11: (rbox_mail_copy(mail_save_context*, mail*)+0x9e) [0x7f7d9689c9ee]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  12: (()+0x375a) [0x7f7d9989475a]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  13: (()+0x4cfa6) [0x7f7d9958afa6]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  14: (mail_deliver_save()+0x1a9) [0x7f7d99895a69]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  15: (mail_deliver()+0x216) [0x7f7d998960d6]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  16: (lmtp_local_data()+0x6eb) [0x5645eb88b7ab]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  17: (cmd_data_continue()+0x233) [0x5645eb88a293]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  18: (()+0x4f790) [0x7f7d99213790]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  19: (io_loop_call_io()+0x65) [0x7f7d992a7fb5]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  20: (io_loop_handler_run_internal()+0x10f) [0x7f7d992a989f]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  21: (io_loop_handler_run()+0x52) [0x7f7d992a80b2]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  22: (io_loop_run()+0x38) [0x7f7d992a82d8]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  23: (master_service_run()+0x13) [0x7f7d99224673]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  24: (main()+0x229) [0x5645eb889319]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  25: (__libc_start_main()+0xf5) [0x7f7d98e19445]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  26: (()+0x5445) [0x5645eb889445]
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp: Error:  NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(username)<43884><CRasNum8DltsqwAARmI6dA>: Fatal: master: service(lmtp): child 43884 killed with signal 6 (core dumps disabled - https://dovecot.org/bugreport.html#coredumps)
May 30 17:02:02 dovecot-hostname.localdomain dovecot[41509]: lmtp(43887): Error: SSL context initialization failed, disabling SSL: Couldn't parse DH parameters: error:0906D06C:PEM routines:PEM_read_bio:no start line: Expecting: DH PARAMETERS

Details about the system:

  • SELinux in 'Permissive' mode
  • Updated CentOS 7.5 with kernel 3.10.0-862.3.2.el7.x86_64
  • Official CentOS packages for Dovecot 2.3 as per https://repo.dovecot.org/
  • devtoolset-7 installed in order to build the RPM
  • Details of some relevant packages installed:
ceph-12.2.5-0.el7.x86_64
ceph-base-12.2.5-0.el7.x86_64
ceph-common-12.2.5-0.el7.x86_64
ceph-mds-12.2.5-0.el7.x86_64
ceph-mgr-12.2.5-0.el7.x86_64
ceph-mon-12.2.5-0.el7.x86_64
ceph-osd-12.2.5-0.el7.x86_64
ceph-selinux-12.2.5-0.el7.x86_64
dovecot-2.3.1-1.x86_64
dovecot-ceph-plugin-0.0.10-0.el7.cern.x86_64
dovecot-ceph-plugin-debuginfo-0.0.10-0.el7.cern.x86_64
dovecot-devel-2.3.1-1.x86_64
dovecot-imaptest-2.3.1-1.x86_64
libcephfs2-12.2.5-0.el7.x86_64
librados2-12.2.5-0.el7.x86_64
librados-devel-12.2.5-0.el7.x86_64
libradosstriper1-12.2.5-0.el7.x86_64
librmb0-0.0.10-0.el7.cern.x86_64
librmb-devel-0.0.10-0.el7.cern.x86_64
python-cephfs-12.2.5-0.el7.x86_64
python-rados-12.2.5-0.el7.x86_64
rmb-tools-0.0.10-0.el7.cern.x86_64

I have built the plugin RPM based on the dovecot-ceph-pugin code in release 0.0.10.

CEPH client configuration:

$ cat /etc/ceph/ceph.client.dovecot.keyring 
[client.dovecot]
key = A..
caps mgr = "allow r"
caps mon = "allow r"
caps osd = "allow rwx pool=mail_storage"
$ ls -l /etc/ceph/ceph.client.dovecot.keyring
-rw-r--r--. 1 root root 148 May 30 15:23 /etc/ceph/ceph.client.dovecot.keyring
$

Dovecot configuration:

$ cat /etc/dovecot/conf.d/90-plugin.conf
plugin {
  rbox_cluster_name = ceph
  rados_user_name = client.dovecot
  rbox_pool_name = mail_storage
  rbox_cfg_object_name = rbox_cfg
  rbox_bugfix_cephfs_21652 = false
  rados_save_log = /home/mail/rbox_save_file.log
}

rmb works as normal user:

$ rmb -u client.dovecot -p mail_storage cfg show
Configuration : rbox_cfg
  user_mapping=false
  user_ns=users
  user_suffix=_u
  rbox_public_namespace=public
  rbox_update_attributes=false
  rbox_mail_attributes=MGPORZVBUI
  rbox_updateable_attributes=B
  rbox_metadata_storage=default
  rbox_storage_metadata_attr=ima
$ 

Attaching more debug information:

Let me know if I can do further changes/tests.

@giacomd
Copy link
Author

giacomd commented May 30, 2018

I now realise this may be linked with the absence of ssl_dh=</path/to/dh.pem in the Dovecot config.

I am now checking this.

@giacomd
Copy link
Author

giacomd commented May 31, 2018

No, even with a correct ssl_dh configuration the error is still the same (minus the initial Error: SSL context initialization failed, disabling SSL: Couldn't parse DH parameters: error:0906D06C:PEM routines:PEM_read_bio:no start line: Expecting: DH PARAMETERS which now disappeared).

Maybe something linked with instructing the plugin to check the DH params?

@dalgaaf
Copy link
Collaborator

dalgaaf commented Jun 1, 2018

Can you access the pool with the same key/client via the ceph/rados tools from the same machine?

Can you run 'ceph osd blacklist ls' ? Are there any clients blacklisted?

@giacomd
Copy link
Author

giacomd commented Jun 1, 2018

Can you access the pool with the same key/client via the ceph/rados tools from the same machine?

Yes. I have to use dovecot and not client.dovecot though - I think it is normal:

$ rados --id dovecot -p mail_storage ls
rbox_cfg
$ rados --id client.dovecot -p mail_storage ls
2018-06-01 09:43:58.714534 2b5b39c17080 -1 auth: unable to find a keyring on /etc/ceph/ceph.client.client.dovecot.keyring,/etc/ceph/ceph.keyring,/etc/ceph/keyring,/etc/ceph/keyring.bin,: (2) No such file or directory
2018-06-01 09:43:58.716668 2b5b39c17080 -1 monclient: authenticate NOTE: no keyring found; disabled cephx authentication
2018-06-01 09:43:58.716678 2b5b39c17080  0 librados: client.client.dovecot authentication error (95) Operation not supported
couldn't connect to cluster: (95) Operation not supported
$ 

Can you run 'ceph osd blacklist ls' ? Are there any clients blacklisted?

Doesn't seem so:

$ ceph --id dovecot osd blacklist ls
listed 0 entries
$ 

@dalgaaf
Copy link
Collaborator

dalgaaf commented Jun 13, 2018

@giacomd Any luck with the CentOS container Jan provided?

@giacomd
Copy link
Author

giacomd commented Jun 15, 2018

@dalgaaf no luck so far, but the error is now different. I will have a look with our CEPH experts to reproduce and have their opinion.

@jrse
Copy link
Contributor

jrse commented Aug 13, 2018

@giacomd did you make it work?

@jrse
Copy link
Contributor

jrse commented Sep 16, 2018

closed due to inactivity, if problem still exists, please reopen.

@jrse jrse closed this as completed Sep 16, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants