Hi,
Quoting Michael Menge <michael.menge@xxxxxxxxxxxxxxxxxxxx>:
Hi,
Quoting Albert Shih <Albert.Shih@xxxxxxxx>:
Le 17/09/2018 à 14:01:52+0200, Michael Menge a écrit
Hi,
we recently upgrade from Cyrus-Imapd 2.4.x to 3.0.8. After some initial
problems
which we could fix cyrus imapd 3.0.8 is running stable. The one remaining
problem
we receive reports about is, that the search is not working/too slow.
First we discovered that one of the options for Squatter are not supported
anymore, "-s Skip mailboxes whose index file is older than their current
squat file (within a small time delta)." and that squatter does not like
"-r" in combination with the source "user"
> squatter -C /etc/imapd_be.conf -r user
fatal error: Internal error: assertion failed: lib/cyrusdb_twoskip.c:
2339: keylen
But after reindexing all mailboxes the search is still slow. I tried to
debug this and
found with strace that cyrus didn't try to open the cyrus.squat
file for the
mailbox.
I suspect that I am missed some configuration change. So here is our
imapd.conf for our backends
If I'm correct you need :
search_fuzzy_always: on
in your config.
If you can tell me if it's work...I would really appreciate. Because I
activated that but I'm not able to see if it's work really.
Thanks for your help.
I did tried it on my test server and it seems to be a bit faster,
but that could be due to caching. Strace still didn't show any access
to the cyrus.squat file.
For information: We only use squatter. No Xapia. And we had much faster
search with Cyrus-Imapd 2.3.x and 2.4.x. I don't have the timings form
the old system but our users are complaining and they receive timeouts
in our horde/imp webmailer, which they did't receive before.
Any other ideas are appreciated.
I still have the problem that search in cyrus imap 3.0.8 with search engine
squatter is slow compared to 2.4.20. I try to figure out if the squatter
search engine is working in cyurs imapd 3.0 and I messed up my configuration,
or if my configuration should work but squatter is broken.
I did set up a test environment to compare the old and new versions.
To verify that the search is indeed slower with 3.0.8
I used two different searches 'B SEARCH TEXT "Test"' and 'B SEARCH
HEADER X-comment Unirundmail'
=== 2.4.20 === SEARCH TEXT
A SELECT INBOX
* 4321 EXISTS
* 4321 RECENT
* FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
* OK [UNSEEN 1] Ok
* OK [UIDVALIDITY 1540372444] Ok
* OK [UIDNEXT 93369] Ok
* OK [HIGHESTMODSEQ 2] Ok
* OK [URLMECH INTERNAL] Ok
A OK [READ-WRITE] Completed
B SEARCH TEXT "Test"
* SEARCH 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23
24 25 26 27 28 29 30 31 33 34 35 36 37 38 39
....
4292 4294 4295 4296 4298 4299 4300 4301 4303 4306 4307 4309 4310 4315
4316 4317 4318 4321
B OK Completed (1996 msgs in 0.690 secs)
=== 3.0.8 === SEARCH TEXT
a SELECT INBOX
* 4321 EXISTS
* 0 RECENT
* FLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk $Forwarded
$mdnsent $label1 $label2 $label3 hordetest testflag)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk
$Forwarded $mdnsent $label1 $label2 $label3 hordetest testflag \*)] Ok
* OK [UNSEEN 3737] Ok
* OK [UIDVALIDITY 1238498084] Ok
* OK [UIDNEXT 93373] Ok
* OK [HIGHESTMODSEQ 98491] Ok
* OK [URLMECH INTERNAL] Ok
* OK [ANNOTATIONS 65536] Ok
a OK [READ-WRITE] Completed
B SEARCH TEXT "Test"
* SEARCH 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23
24 25 26 27 28 29 30 31 33 34 35 36 37 38 39
....
4274 4275 4276 4277 4278 4279 4285 4286 4287 4288 4292 4294 4295 4296
4298 4299 4300 4301 4303 4306 4307 4309 4310 4315 4316 4317 4318 4321
B OK Completed (1935 msgs in 2.580 secs)
==== 2.4.20 === SEARCH HEADER
a SELECT INBOX
* 4321 EXISTS
* 0 RECENT
* FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
* OK [UNSEEN 1] Ok
* OK [UIDVALIDITY 1540372444] Ok
* OK [UIDNEXT 93369] Ok
* OK [HIGHESTMODSEQ 2] Ok
* OK [URLMECH INTERNAL] Ok
a OK [READ-WRITE] Completed
b SEARCH HEADER X-comment Unirundmail
* SEARCH 4283 4291 4313 4319 4320
b OK Completed (5 msgs in 0.020 secs)
==== 3.0.8 === SEARCH HEADER
a SELECT INBOX
* 4321 EXISTS
* 0 RECENT
* FLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk $Forwarded
$mdnsent $label1 $label2 $label3 hordetest testflag)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen NonJunk
$Forwarded $mdnsent $label1 $label2 $label3 hordetest testflag \*)] Ok
* OK [UNSEEN 3737] Ok
* OK [UIDVALIDITY 1238498084] Ok
* OK [UIDNEXT 93373] Ok
* OK [HIGHESTMODSEQ 98491] Ok
* OK [URLMECH INTERNAL] Ok
* OK [ANNOTATIONS 65536] Ok
a OK [READ-WRITE] Completed
b SEARCH HEADER X-comment Unirundmail
* SEARCH 4283 4291 4313 4319 4320
b OK Completed (5 msgs in 0.370 secs)
===
There is also a big discrepancy between time indicated in the "OK
Completed" and the time from
sending the search command till the return of the result, which is
0.890 sec compared to ~30 sec
on the production system.
I used strace on the imapd processes while searching to verify that
the squat file was used
in 2.4 but not in 3.0.
I could see open events for the squat file and the messages that where
found for 2.4.20
and no open event (not even a failed one) to the squat file but
instead open events for
all message files in that folder for 3.0.8
I read the documentation and source code and tried to figure out if i
am missing some
config options, or if i could pinpoint a function where the search was
turning the
wrong way. I used "perf -g" the see the call graphs and to figure out
where the
call graphs change
I can see that the same functions are called up to "index_search", and
that the called functions
change at that point. I know that the search code got restructured to
support different search
engines and that some functions got renamed. I have attached the perf
report output, so that
someone with a better understanding of the code can see whats going
on. I can provide the
perf.data files if it helps.
Can someone confirm or refute that the squatter search engine is
working with cyrus imapd 3.0.x?
Is "search_engine: squat" in imapd.conf and a "squatter" event in
cyrus.conf is sufficient to
use the squatter search index in 3.0 or are there other options steps
required.
Regards
Michael Menge
PS. link to my original post with my imapd.conf
https://lists.andrew.cmu.edu/pipermail/info-cyrus/2018-September/040395.html
--------------------------------------------------------------------------------
M.Menge Tel.: (49) 7071/29-70316
Universität Tübingen Fax.: (49) 7071/29-5912
Zentrum für Datenverarbeitung mail:
michael.menge@xxxxxxxxxxxxxxxxxxxx
Wächterstraße 76
72074 Tübingen
Samples: 2K of event 'cpu-clock', Event count (approx.): 677500000
Children Self Command Shared Object Symbol
+ 97,05% 0,00% imapd libc-2.17.so [.] __libc_start_main
+ 97,05% 0,00% imapd imapd [.] main
+ 97,05% 0,00% imapd imapd [.] service_main
+ 97,05% 0,00% imapd imapd [.] cmdloop
+ 97,01% 0,00% imapd imapd [.] cmd_search
+ 97,01% 0,00% imapd imapd [.] index_search
+ 96,83% 0,18% imapd imapd [.] _index_search
+ 94,13% 0,00% imapd imapd [.] index_search_evaluate
+ 89,41% 0,00% imapd imapd [.] index_searchmsg
+ 72,29% 18,01% imapd imapd [.] convert_putc
+ 67,79% 0,00% imapd imapd [.] charset_decode_mimeheader
+ 67,42% 0,26% imapd imapd [.] mimeheader_cat
+ 56,13% 3,87% imapd imapd [.] stripnl2uni
+ 51,29% 12,73% imapd imapd [.] table2uni
+ 48,56% 3,87% imapd imapd [.] convert_cat
+ 37,16% 17,93% imapd imapd [.] uni2searchform
+ 17,38% 1,48% imapd imapd [.] convert_catn
+ 16,97% 3,76% imapd imapd [.] uni2utf8
+ 12,95% 1,81% imapd imapd [.] charset_searchstring
+ 9,67% 2,14% imapd imapd [.] byte2buffer
+ 7,71% 3,06% imapd imapd [.] buf_putc
+ 6,38% 6,38% imapd imapd [.] byte2search
+ 6,13% 0,33% imapd imapd [.] charset_searchfile
+ 5,39% 5,39% imapd imapd [.] search_havematch
+ 4,80% 4,80% imapd imapd [.] buf_ensure
+ 3,87% 0,52% imapd imapd [.] qp2byte
+ 3,58% 0,00% imapd [kernel.kallsyms] [k] system_call_fastpath
+ 2,58% 0,37% imapd imapd [.] utf8_2uni
+ 1,88% 0,85% imapd libc-2.17.so [.] __memcpy_ssse3_back
+ 1,73% 0,00% imapd [kernel.kallsyms] [k] async_page_fault
+ 1,73% 0,00% imapd [kernel.kallsyms] [k] do_async_page_fault
+ 1,73% 0,00% imapd [kernel.kallsyms] [k] trace_do_page_fault
+ 1,73% 0,00% imapd libc-2.17.so [.] __GI___libc_open
+ 1,70% 0,48% imapd [kernel.kallsyms] [k] __do_page_fault
+ 1,66% 0,00% imapd imapd [.] mailbox_unmap_message
+ 1,66% 0,22% imapd libc-2.17.so [.] __GI___munmap
+ 1,66% 0,04% imapd [kernel.kallsyms] [k] sys_open
+ 1,62% 0,04% imapd [kernel.kallsyms] [k] do_sys_open
+ 1,40% 0,00% imapd [kernel.kallsyms] [k] do_filp_open
+ 1,40% 0,00% imapd [kernel.kallsyms] [k] path_openat
Samples: 10K of event 'cpu-clock', Event count (approx.): 2575000000
Children Self Command Shared Object Symbol
+ 95,97% 0,00% imapd libc-2.17.so [.] __libc_start_main
+ 95,97% 0,00% imapd imapd [.] main
+ 95,97% 0,00% imapd imapd [.] service_main
+ 95,96% 0,00% imapd imapd [.] cmdloop
+ 95,94% 0,00% imapd imapd [.] cmd_search
+ 95,92% 0,00% imapd libcyrus_imap.so.0.0.0 [.] index_search
+ 95,89% 0,00% imapd libcyrus_imap.so.0.0.0 [.] search_query_run
+ 95,89% 0,00% imapd libcyrus_imap.so.0.0.0 [.] subquery_run_global
+ 95,83% 0,07% imapd libcyrus_imap.so.0.0.0 [.] subquery_run_one_folder
+ 95,64% 0,03% imapd libcyrus_imap.so.0.0.0 [.] index_search_evaluate
+ 93,86% 0,09% imapd libcyrus_imap.so.0.0.0 [.] search_expr_evaluate
+ 93,76% 0,00% imapd libcyrus_imap.so.0.0.0 [.] search_text_match
+ 93,76% 0,01% imapd libcyrus_imap.so.0.0.0 [.] message_foreach_section
+ 86,83% 0,04% imapd libcyrus_imap.so.0.0.0 [.] body_foreach_section
+ 76,50% 0,07% imapd libcyrus_imap.so.0.0.0 [.] searchmsg_cb
+ 66,19% 13,46% imapd libcyrus.so.0.0.0 [.] convert_putc
+ 40,93% 0,02% imapd libcyrus.so.0.0.0 [.] charset_search_mimeheader
+ 39,92% 0,06% imapd libcyrus.so.0.0.0 [.] mimeheader_cat
+ 35,86% 17,84% imapd libcyrus.so.0.0.0 [.] uni2searchform
+ 35,02% 1,14% imapd libcyrus.so.0.0.0 [.] charset_searchfile
+ 33,60% 3,21% imapd libcyrus.so.0.0.0 [.] unfold2uni
+ 32,97% 7,95% imapd libcyrus.so.0.0.0 [.] table2uni
+ 28,36% 2,12% imapd libcyrus.so.0.0.0 [.] convert_cat
+ 17,54% 2,46% imapd libcyrus.so.0.0.0 [.] qp2byte
+ 16,17% 4,20% imapd libcyrus.so.0.0.0 [.] uni2utf8
+ 15,13% 1,71% imapd libcyrus.so.0.0.0 [.] qp_flushline
+ 12,39% 2,43% imapd libcyrus.so.0.0.0 [.] utf8_2uni
+ 10,20% 0,70% imapd libcyrus.so.0.0.0 [.] convert_catn
+ 10,04% 10,04% imapd libcyrus.so.0.0.0 [.] byte2search
+ 9,26% 1,34% imapd libcyrus_imap.so.0.0.0 [.] message_parse_headers
+ 7,58% 1,45% imapd libcyrus.so.0.0.0 [.] b64_2byte
+ 6,85% 0,12% imapd libcyrus_imap.so.0.0.0 [.] message_need
+ 6,32% 2,34% imapd libcyrus.so.0.0.0 [.] icu2uni
+ 5,32% 4,53% imapd libcyrus_imap.so.0.0.0 [.] message_getline
+ 3,93% 0,01% imapd [kernel.kallsyms] [k] system_call_fastpath
+ 2,89% 2,89% imapd libcyrus.so.0.0.0 [.] search_havematch
+ 2,31% 0,01% imapd libpthread-2.17.so [.] __open_nocancel
+ 2,26% 0,01% imapd [kernel.kallsyms] [k] sys_open
+ 2,24% 0,01% imapd [kernel.kallsyms] [k] do_sys_open
+ 2,11% 0,00% imapd [kernel.kallsyms] [k] do_filp_open
Samples: 1K of event 'cpu-clock', Event count (approx.): 345000000
Children Self Command Shared Object Symbol
+ 75,29% 0,00% imapd libc-2.17.so [.] __libc_start_main
+ 75,29% 0,00% imapd imapd [.] main
+ 75,29% 0,00% imapd imapd [.] service_main
+ 74,86% 0,00% imapd imapd [.] cmdloop
+ 74,49% 0,00% imapd imapd [.] cmd_search
+ 74,35% 0,00% imapd libcyrus_imap.so.0.0.0 [.] index_search
+ 73,41% 0,00% imapd libcyrus_imap.so.0.0.0 [.] search_query_run
+ 73,41% 0,00% imapd libcyrus_imap.so.0.0.0 [.] subquery_run_global
+ 73,26% 0,14% imapd libcyrus_imap.so.0.0.0 [.] subquery_run_one_folder
+ 72,54% 0,43% imapd libcyrus_imap.so.0.0.0 [.] index_search_evaluate
+ 62,68% 0,51% imapd libcyrus_imap.so.0.0.0 [.] search_expr_evaluate
+ 62,03% 0,29% imapd libcyrus_imap.so.0.0.0 [.] search_header_match
+ 54,06% 0,29% imapd libcyrus_imap.so.0.0.0 [.] message_get_field
+ 40,94% 0,29% imapd libcyrus_imap.so.0.0.0 [.] message_need
+ 20,07% 0,14% imapd [kernel.kallsyms] [k] system_call_fastpath
+ 11,01% 0,36% imapd libpthread-2.17.so [.] __open_nocancel
+ 10,58% 0,07% imapd libcyrus_imap.so.0.0.0 [.] message_parse_cbodystructure
+ 10,14% 0,14% imapd libcyrus_imap.so.0.0.0 [.] mailbox_cacherecord
+ 9,78% 0,00% imapd [kernel.kallsyms] [k] sys_open
+ 9,71% 0,14% imapd [kernel.kallsyms] [k] do_sys_open
+ 9,64% 0,43% imapd libcyrus_imap.so.0.0.0 [.] parse_bodystructure_part
+ 9,13% 3,70% imapd libc-2.17.so [.] __strncpy_sse2_unaligned
+ 8,62% 0,00% imapd [kernel.kallsyms] [k] do_filp_open
+ 8,62% 0,00% imapd [kernel.kallsyms] [k] path_openat
+ 8,26% 0,14% imapd libcyrus_imap.so.0.0.0 [.] message_free
+ 8,19% 0,00% imapd libcyrus_imap.so.0.0.0 [.] message_unref
+ 7,97% 0,07% imapd libcyrus_imap.so.0.0.0 [.] message_yield
+ 7,83% 0,65% imapd libcyrus_min.so.0.0.0 [.] buf_free
+ 7,10% 0,22% imapd libcyrus_min.so.0.0.0 [.] _buf_free_data
+ 6,96% 0,36% imapd libc-2.17.so [.] __GI___munmap
+ 6,38% 1,38% imapd libcyrus_imap.so.0.0.0 [.] getxstring
+ 6,30% 0,07% imapd [kernel.kallsyms] [k] trace_do_page_fault
+ 6,30% 0,00% imapd [kernel.kallsyms] [k] async_page_fault
+ 6,30% 0,00% imapd [kernel.kallsyms] [k] do_async_page_fault
+ 6,09% 0,00% imapd libcyrus_imap.so.0.0.0 [.] mailbox_cachefile
+ 6,09% 1,81% imapd [kernel.kallsyms] [k] __do_page_fault
+ 6,01% 0,07% imapd libcyrus.so.0.0.0 [.] charset_searchstring
+ 5,80% 0,14% imapd libc-2.17.so [.] __mmap64
+ 5,36% 0,14% imapd libcyrus_imap.so.0.0.0 [.] mboxname_hash
+ 5,36% 0,22% imapd libcyrus_imap.so.0.0.0 [.] mailbox_record_fname
Samples: 37 of event 'cpu-clock', Event count (approx.): 9250000
Children Self Command Shared Object Symbol
+ 91,89% 0,00% imapd libc-2.17.so [.] __libc_start_main
+ 91,89% 0,00% imapd imapd [.] main
+ 91,89% 0,00% imapd imapd [.] service_main
+ 83,78% 0,00% imapd imapd [.] cmdloop
+ 81,08% 0,00% imapd imapd [.] cmd_search
+ 81,08% 0,00% imapd imapd [.] index_search
+ 67,57% 0,00% imapd imapd [.] _index_search
+ 64,86% 0,00% imapd imapd [.] search_prefilter_messages
+ 64,86% 0,00% imapd imapd [.] search_squat
+ 56,76% 0,00% imapd imapd [.] squat_search_list_docs
+ 54,05% 2,70% imapd imapd [.] drop_indexed_docs
+ 51,35% 8,11% imapd imapd [.] parse_doc_name
+ 40,54% 29,73% imapd imapd [.] index_finduid
+ 13,51% 13,51% imapd imapd [.] index_getuid
+ 13,51% 0,00% imapd imapd [.] index_check
+ 10,81% 5,41% imapd imapd [.] index_refresh
+ 8,11% 0,00% imapd imapd [.] imapd_reset
+ 8,11% 0,00% imapd [kernel.kallsyms] [k] system_call_fastpath
+ 8,11% 0,00% imapd imapd [.] search_squat_do_query
+ 8,11% 0,00% imapd imapd [.] search_strlist
+ 8,11% 0,00% imapd imapd [.] squat_search_execute
+ 5,41% 0,00% imapd libc-2.17.so [.] __GI___libc_open
+ 5,41% 0,00% imapd [kernel.kallsyms] [k] sys_open
+ 5,41% 0,00% imapd [kernel.kallsyms] [k] do_sys_open
+ 5,41% 0,00% imapd [kernel.kallsyms] [k] do_filp_open
+ 5,41% 0,00% imapd [kernel.kallsyms] [k] path_openat
+ 5,41% 0,00% imapd [kernel.kallsyms] [k] do_last
+ 5,41% 2,70% imapd imapd [.] mailbox_buf_to_index_record
+ 5,41% 0,00% imapd imapd [.] mailbox_read_index_record
+ 5,41% 5,41% imapd libc-2.17.so [.] __GI_____strtoll_l_internal
+ 2,70% 2,70% imapd [kernel.kallsyms] [k] flex_array_get_ptr
+ 2,70% 2,70% imapd [kernel.kallsyms] [k] do_dentry_open
+ 2,70% 2,70% imapd [kernel.kallsyms] [k] unmap_page_range
+ 2,70% 2,70% imapd imapd [.] count_docs_containing_word
+ 2,70% 2,70% imapd imapd [.] filter_doc
+ 2,70% 2,70% imapd imapd [.] filter_to_docs_containing_word
+ 2,70% 2,70% imapd imapd [.] squat_decode_I
+ 2,70% 2,70% imapd libc-2.17.so [.] __memcpy_ssse3_back
+ 2,70% 0,00% imapd [kernel.kallsyms] [k] may_open
+ 2,70% 0,00% imapd [kernel.kallsyms] [k] inode_permission
----
Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
