search

ceph-dovecot / dovecot-ceph-plugin

Dovecot plugin for storing mails in a Ceph cluster
Other
131 stars 23 forks source link

I am getting this error, when adding a message to a mailbox/folder #259

Closed f1-outsourcing closed 5 years ago

f1-outsourcing commented 5 years ago

Sep 15 00:58:09 mail04 dovecot: imap-login: Login: user=, method=PLAIN, rip=192.168.x.x, lip=192.168.x.x, mpid=23859, TLS, session=<7ZP3TYuSE8nAqArb> Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Loading modules from directory: /usr/lib64/dovecot Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Module loaded: /usr/lib64/dovecot/lib15_notify_plugin.so Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Module loaded: /usr/lib64/dovecot/lib20_listescape_plugin.so Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Module loaded: /usr/lib64/dovecot/libstorage_rbox_plugin.so Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Added userdb setting: mail=rbox:~/rbox Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Effective uid=8267, gid=231, home=/home/popusers/test Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=rbox:~/rbox Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: fs: root=/home/popusers/test/rbox, index=, indexpvt=, control=, inbox=, alt= Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: test: Mailbox opened because: append Sep 15 00:58:09 mail04 dovecot: imap: Error: Thread::try_create(): pthread_create failed with error 11/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/cent os7/MACHINE_SIZE/huge/release/12.2.12/rpm/el7/BUILD/ceph-12.2.12/src/common/Thread.cc: In function 'void Thread::create(const char, size_t)' thread 7f57828e8740 time 2019-09-15 00:58:09.828866 Sep 15 00:58:09 mail04 dovecot: imap: 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.12/rpm/el7/BUILD/ceph- 12.2.12/src/common/Thread.cc: 152: FAILED assert(ret == 0) Sep 15 00:58:09 mail04 dovecot: imap: Error: ceph version 12.2.12 (1436006594665279fe734b4c15d7e08c13ebd777) luminous (stable) Sep 15 00:58:09 mail04 dovecot: imap: Error: 1: (ceph::__ceph_assert_fail(char const, char const, int, char const)+0x110) [0x7f5777817fd0] Sep 15 00:58:09 mail04 dovecot: imap: Error: 2: (Thread::create(char const, unsigned long)+0xba) [0x7f5777a68f4a] Sep 15 00:58:09 mail04 dovecot: imap: Error: 3: (SafeTimer::init()+0x99) [0x7f57778111d9] Sep 15 00:58:09 mail04 dovecot: imap: Error: 4: (MgrClient::init()+0x30) [0x7f5777875d50] Sep 15 00:58:09 mail04 dovecot: imap: Error: 5: (librados::RadosClient::connect()+0x13da) [0x7f5780b1e19a] Sep 15 00:58:09 mail04 dovecot: imap: Error: 6: (librmb::RadosClusterImpl::connect()+0x43) [0x7f578100c081] Sep 15 00:58:09 mail04 dovecot: imap: Error: 7: (librmb::RadosClusterImpl::io_ctx_create(std::string const&, librados::IoCtx)+0x66) [0x7f578100c2ec] Sep 15 00:58:09 mail04 dovecot: imap: Error: 8: (librmb::RadosStorageImpl::create_connection(std::string const&)+0x3f) [0x7f578100eb9d] Sep 15 00:58:09 mail04 dovecot: imap: Error: 9: (librmb::RadosStorageImpl::open_connection(std::string const&, std::string const&, std::string const&)+0xa6) [0x7f578100eb0a] Sep 15 00:58:09 mail04 dovecot: imap: Error: 10: (rbox_open_rados_connection()+0x1ca) [0x7f578125e412] Sep 15 00:58:09 mail04 dovecot: imap: Error: 11: (rbox_save_begin(mail_save_context, istream)+0x91) [0x7f5781257caf] Sep 15 00:58:09 mail04 dovecot: imap: Error: 12: (mailbox_save_begin()+0x83) [0x7f57821c63f3] Sep 15 00:58:09 mail04 dovecot: imap: Error: 13: (()+0xf423) [0x55f9bbc6c423] Sep 15 00:58:09 mail04 dovecot: imap: Error: 14: (cmd_append()+0x134) [0x55f9bbc6ca54] Sep 15 00:58:09 mail04 dovecot: imap: Error: 15: (command_exec()+0x5c) [0x55f9bbc79fbc] Sep 15 00:58:09 mail04 dovecot: imap: Error: 16: (()+0x1b53f) [0x55f9bbc7853f] Sep 15 00:58:09 mail04 dovecot: imap: Error: 17: (()+0x1b5d1) [0x55f9bbc785d1] Sep 15 00:58:09 mail04 dovecot: imap: Error: 18: (client_handle_input()+0x195) [0x55f9bbc78995] Sep 15 00:58:09 mail04 dovecot: imap: Error: 19: (client_input()+0x85) [0x55f9bbc78eb5] Sep 15 00:58:09 mail04 dovecot: imap: Error: 20: (io_loop_call_io()+0x52) [0x7f5781efcbe2] Sep 15 00:58:09 mail04 dovecot: imap: Error: 21: (io_loop_handler_run_internal()+0x10f) [0x7f5781efe2cf] Sep 15 00:58:09 mail04 dovecot: imap: Error: 22: (io_loop_handler_run()+0x3c) [0x7f5781efcc7c] Sep 15 00:58:09 mail04 dovecot: imap: Error: 23: (io_loop_run()+0x38) [0x7f5781efce38] Sep 15 00:58:09 mail04 dovecot: imap: Error: 24: (master_service_run()+0x13) [0x7f5781e81c03] Sep 15 00:58:09 mail04 dovecot: imap: Error: 25: (main()+0x322) [0x55f9bbc6b262] Sep 15 00:58:09 mail04 dovecot: imap: Error: 26: (__libc_start_main()+0xf5) [0x7f5781a9b495] Sep 15 00:58:09 mail04 dovecot: imap: Error: 27: (()+0xe3fd) [0x55f9bbc6b3fd] Sep 15 00:58:09 mail04 dovecot: imap: Error: NOTE: a copy of the executable, or objdump -rdS <executable> is needed to interpret this. Sep 15 00:58:09 mail04 dovecot: imap(test): Fatal: master: service(imap): child 23859 killed with signal 6 (core dumps disabled) Sep 15 00:58:09 mail04 dovecot: imap-login: Login: user=, method=PLAIN, rip=192.168.x.x, lip=192.168.x.x, mpid=23870, TLS, session= Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Loading modules from directory: /usr/lib64/dovecot Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Module loaded: /usr/lib64/dovecot/lib15_notify_plugin.so Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Module loaded: /usr/lib64/dovecot/lib20_listescape_plugin.so Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Module loaded: /usr/lib64/dovecot/libstorage_rbox_plugin.so Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Added userdb setting: mail=rbox:~/rbox Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Effective uid=8267, gid=231, home=/home/popusers/test Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=rbox:~/rbox Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: fs: root=/home/popusers/test/rbox, index=, indexpvt=, control=, inbox=, alt= Sep 15 00:58:09 mail04 dovecot: imap(test): Debug: test: Mailbox opened because: append Sep 15 00:58:09 mail04 dovecot: imap: Error: Thread::try_create(): pthread_create failed with error 11/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.12/rpm/el7/BUILD/ceph-12.2.12/src/common/Thread.cc: In function 'void Thread::create(const char, size_t)' thread 7f0354a4f740 time 2019-09-15 00:58:09.974626 Sep 15 00:58:09 mail04 dovecot: imap: 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.12/rpm/el7/BUILD/ceph-12.2.12/src/common/Thread.cc: 152: FAILED assert(ret == 0) Sep 15 00:58:09 mail04 dovecot: imap: Error: ceph version 12.2.12 (1436006594665279fe734b4c15d7e08c13ebd777) luminous (stable) Sep 15 00:58:09 mail04 dovecot: imap: Error: 1: (ceph::__ceph_assert_fail(char const, char const, int, char const)+0x110) [0x7f034997efd0] Sep 15 00:58:09 mail04 dovecot: imap: Error: 2: (Thread::create(char const, unsigned long)+0xba) [0x7f0349bcff4a] Sep 15 00:58:09 mail04 dovecot: imap: Error: 3: (SafeTimer::init()+0x99) [0x7f03499781d9] Sep 15 00:58:09 mail04 dovecot: imap: Error: 4: (MgrClient::init()+0x30) [0x7f03499dcd50] Sep 15 00:58:09 mail04 dovecot: imap: Error: 5: (librados::RadosClient::connect()+0x13da) [0x7f0352c8519a] Sep 15 00:58:09 mail04 dovecot: imap: Error: 6: (librmb::RadosClusterImpl::connect()+0x43) [0x7f0353173081] Sep 15 00:58:09 mail04 dovecot: imap: Error: 7: (librmb::RadosClusterImpl::io_ctx_create(std::string const&, librados::IoCtx)+0x66) [0x7f03531732ec] Sep 15 00:58:09 mail04 dovecot: imap: Error: 8: (librmb::RadosStorageImpl::create_connection(std::string const&)+0x3f) [0x7f0353175b9d] Sep 15 00:58:09 mail04 dovecot: imap: Error: 9: (librmb::RadosStorageImpl::open_connection(std::string const&, std::string const&, std::string const&)+0xa6) [0x7f0353175b0a] Sep 15 00:58:09 mail04 dovecot: imap: Error: 10: (rbox_open_rados_connection()+0x1ca) [0x7f03533c5412] Sep 15 00:58:09 mail04 dovecot: imap: Error: 11: (rbox_save_begin(mail_save_context, istream)+0x91) [0x7f03533becaf] Sep 15 00:58:09 mail04 dovecot: imap: Error: 12: (mailbox_save_begin()+0x83) [0x7f035432d3f3] Sep 15 00:58:09 mail04 dovecot: imap: Error: 13: (()+0xf423) [0x5582474e6423] Sep 15 00:58:09 mail04 dovecot: imap: Error: 14: (cmd_append()+0x134) [0x5582474e6a54] Sep 15 00:58:09 mail04 dovecot: imap: Error: 15: (command_exec()+0x5c) [0x5582474f3fbc] Sep 15 00:58:09 mail04 dovecot: imap: Error: 16: (()+0x1b53f) [0x5582474f253f] Sep 15 00:58:09 mail04 dovecot: imap: Error: 17: (()+0x1b5d1) [0x5582474f25d1] Sep 15 00:58:09 mail04 dovecot: imap: Error: 18: (client_handle_input()+0x195) [0x5582474f2995] Sep 15 00:58:09 mail04 dovecot: imap: Error: 19: (client_input()+0x85) [0x5582474f2eb5] Sep 15 00:58:09 mail04 dovecot: imap: Error: 20: (io_loop_call_io()+0x52) [0x7f0354063be2] Sep 15 00:58:09 mail04 dovecot: imap: Error: 21: (io_loop_handler_run_internal()+0x10f) [0x7f03540652cf] Sep 15 00:58:09 mail04 dovecot: imap: Error: 22: (io_loop_handler_run()+0x3c) [0x7f0354063c7c] Sep 15 00:58:09 mail04 dovecot: imap: Error: 23: (io_loop_run()+0x38) [0x7f0354063e38] Sep 15 00:58:09 mail04 dovecot: imap: Error: 24: (master_service_run()+0x13) [0x7f0353fe8c03] Sep 15 00:58:09 mail04 dovecot: imap: Error: 25: (main()+0x322) [0x5582474e5262] Sep 15 00:58:09 mail04 dovecot: imap: Error: 26: (__libc_start_main()+0xf5) [0x7f0353c02495] Sep 15 00:58:09 mail04 dovecot: imap: Error: 27: (()+0xe3fd) [0x5582474e53fd] Sep 15 00:58:09 mail04 dovecot: imap: Error: NOTE: a copy of the executable, or objdump -rdS <executable> is needed to interpret this. Sep 15 00:58:09 mail04 dovecot: imap(test): Fatal: master: service(imap): child 23870 killed with signal 6 (core dumps disabled)

jrse commented 5 years ago

Increase virtual memory and system limits Stack size , open files.

f1-outsourcing commented 5 years ago

I do not think it is that, it is a 4GB 2 vcpu, test vm does nothing but have one or two dovecot connections. One normal, one configured via ceph.

[@ ~]# free -m
              total        used        free      shared  buff/cache   available
Mem:           3789         214        1256         656        2318        2607
Swap:           999           0         999
f1-outsourcing commented 5 years ago

It is not related to these build warnings?

In file included from dovecot-all.h:26:0,
                 from rbox-save.cpp:23:
/usr/include/dovecot/str.h: In function 'const unsigned char* str_data(const string_t*)':
/usr/include/dovecot/str.h:22:14: warning: invalid conversion from 'const void*' to 'const unsigned char*' [-fpermissive]
  return str->data;
              ^
rbox-save.cpp: In function 'void init_output_stream(mail_save_context*)':
rbox-save.cpp:195:116: warning: invalid conversion from 'const librmb::RadosStorage*' to 'librmb::RadosStorage*' [-fpermissive]
       o_stream_create_bufferlist(r_ctx->rados_mail, &r_ctx->rados_storage, rbox->storage->config->is_write_chunks());
                                                                                                                    ^
In file included from rbox-save.cpp:43:0:
ostream-bufferlist.h:23:17: warning:   initializing argument 2 of 'ostream* o_stream_create_bufferlist(librmb::RadosMail*, librmb::RadosStorage*, bool)' [-fpermissive]
 struct ostream *o_stream_create_bufferlist(librmb::RadosMail *rados_mail, librmb::RadosStorage *rados_storage,
                 ^

And I only have to copy libstorage_rbox_plugin.so, lib10_doveadm_rbox_plugin.so and librmb.so.0 to the test vm?

jrse commented 5 years ago

The problem you see is that the imap process does not have enough resources to create a pthread. This is done in the librados library.

Sep 15 00:58:09 mail04 dovecot: imap: Error: 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x110) [0x7f034997efd0]
Sep 15 00:58:09 mail04 dovecot: imap: Error: 2: (Thread::create(char const*, unsigned long)+0xba) [0x7f0349bcff4a]

Follow theses steps to evaluate that it is working.

  1. set the system limits

ulimit -s unlimited ulimit -n (if you have a lot of users increase this value)

  1. change dovecot config in 10-master.conf

default-vsz-limit=768

  1. start dovecot

dovecot

normally you would set the system limits in the service startup script.

jrse commented 5 years ago

rbox-save.cpp: In function 'void init_output_stream(mail_save_context)': rbox-save.cpp:195:116: warning: invalid conversion from 'const librmb::RadosStorage' to 'librmb::RadosStorage' [-fpermissive] o_stream_create_bufferlist(r_ctx->rados_mail, &r_ctx->rados_storage, rbox->storage->config->is_write_chunks()); ^ In file included from rbox-save.cpp:43:0: ostream-bufferlist.h:23:17: warning: initializing argument 2 of 'ostream o_stream_create_bufferlist(librmb::RadosMail, librmb::RadosStorage, bool)' [-fpermissive] struct ostream o_stream_create_bufferlist(librmb::RadosMail rados_mail, librmb::RadosStorage *rados_storage, ^

not nice that they are there ;.-/, i will remove them soon ( #261), but i think they will have no impact on this specific problem.

f1-outsourcing commented 5 years ago

The problem you see is that the imap process does not have enough resources to create a pthread. This is done in the librados library.

Sep 15 00:58:09 mail04 dovecot: imap: Error: 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x110) [0x7f034997efd0]
Sep 15 00:58:09 mail04 dovecot: imap: Error: 2: (Thread::create(char const*, unsigned long)+0xba) [0x7f0349bcff4a]

Follow theses steps to evaluate that it is working.

1. set the system limits

ulimit -s unlimited ulimit -n (if you have a lot of users increase this value)

1. change dovecot config in 10-master.conf

default-vsz-limit=768

1. start dovecot

dovecot

normally you would set the system limits in the service startup script.

Yes indeed I had to change the vsz_limit limit in the imap section. I have 128MB in the imap-login and had 512MB in imap, changing it there to 768MB resolved it.

jrse commented 5 years ago

:-) great.