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.

Sign up for GitHub

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

Jump to bottom

SearchFuzzy.search_subjectsnippets fails strangely on 3.0 #2348

Closed
elliefm opened this issue May 9, 2018 · 5 comments
Closed

SearchFuzzy.search_subjectsnippets fails strangely on 3.0 #2348

elliefm opened this issue May 9, 2018 · 5 comments
Assignees
@rsto @elliefm
Labels
3.0 affects 3.0

Comments

@elliefm
Copy link
Contributor

elliefm commented May 9, 2018

The entire -vvv output is at the end, but I'll front-load the interesting bits.

The test message's subject:

Subject: [plumbing] Re: log server v0 live

The search:

C: 10 search fuzzy text servers
S: * SEARCH 1
S: 10 OK Completed (1 msgs in 0.001 secs)
C: 11 xsnippets ((inbox 1525837939 (1))) utf-8 (fuzzy text servers)
S: * SNIPPET "INBOX" 1525837939 1 SUBJECT "plumbing] Re: log <b>server</b> v0 live"
S: * SNIPPET "INBOX" 1525837939 1 LISTID "plumbing] Re: log <b>server</b> v0 live...[plumbing] Re: log <b>server</b> v0 live"
S: 11 OK Completed (in 0.001 secs)

The failure:

There was 1 failure:
1) test_search_subjectsnippet(Cassandane::Cyrus::SearchFuzzy)
 plumbing] Re: log <b>server</b> v0 live didn't match /(?^:^\[plumbing\])/ at Cassandane/Cyrus/SearchFuzzy.pm line 1019.

So it's clearly failing because the response to the search doesn't include the "[" at the start of the subject. How do snippets work? Is this a bug in Cyrus 3.0, in that the "[" at the start of the subject is being clipped out? Or is this reasonable snippet behaviour, and the test pattern is assuming too much?

Obviously, this test succeeds on master, but I don't know why. @rsto, any thoughts?

Full output follows:

ellie@debian:master:~/fastmail/cassandane$./testrunner.pl SearchFuzzy.search_subjectsnippet -vvv -fpretty
=====> Cassini[65] Reading /home/ellie/fastmail/cassandane/cassandane.ini
=====> Cyrus::TestCase[565] ---------- BEGIN test_search_subjectsnippet ----------
=====> Instance[1076] start main instance for test test_search_subjectsnippet: basedir /dev/shm/cass/0352180101
=====> Instance[1059] started smtpd as 17100
=====> Instance[473] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[473] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1595] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/0352180101/conf/imapd.conf"
2018/05/09-13:52:18 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(17100)
Resolved [localhost]:9100 to [::1]:9100, IPv6
Resolved [localhost]:9100 to [127.0.0.1]:9100, IPv4
Binding to TCP port 9100 on host ::1 with IPv6
Binding to TCP port 9100 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[473] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[473] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[947] started saslauthd for /dev/shm/cass/0352180101 as 17104
=====> Instance[1858] opening socket /dev/shm/cass/0352180101/run/mux
=====> Instance[974] started notifyd for /dev/shm/cass/0352180101 as 17105
=====> Instance[890] _start_master: logging to /dev/shm/cass/0352180101/conf/master.log
=====> Instance[473] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1595] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/0352180101/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/0352180101/run/master.pid" "-d" "-M" "/dev/shm/cass/0352180101/conf/cyrus.conf" "-L" "/dev/shm/cass/0352180101/conf/master.log"
=====> Instance[899] _start_master: waiting for PID file
=====> Instance[902] _start_master: PID file present and correct
=====> Instance[914] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9101
=====> Util::Wait[75] Waited 0.023434 sec for 127.0.0.1:9101 to be in LISTEN state
=====> Instance[925] _start_master: all services listening
=====> Instance[1001] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9101
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN SASL-IR] debian Cyrus IMAP 3.0.6 server ready
S: * CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE
S: 1 OK Completed
C: 2 login admin "testpw"
=====> Instance[1873] authdaemon connection: admin testpw imap 
S: 2 OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY LOGINDISABLED XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in SESSIONID=<0352180101-17113-1525837938-1-6308073221863479862>
C: 3 create user.cassandane
S: 3 OK Completed
C: 4 setacl user.cassandane admin lrswipkxtecdan
S: 4 OK Completed
C: 5 setacl user.cassandane cassandane lrswipkxtecdn
S: 5 OK Completed
C: 6 setacl user.cassandane anyone p
S: 6 OK Completed
A: is_open test
A: is_open test received timeout, still open
C: 7 logout
S: * BYE LOGOUT received
S: 7 OK Completed
A: Release socket, fileno=10
=====> Instance[1111] started main instance for test test_search_subjectsnippet: cyrus version 3.0.6
=====> Cyrus::TestCase[572] Calling test function
=====> Cyrus::SearchFuzzy[76] Xapian flavor 'cyruslibs' detected.

=====> Cyrus::SearchFuzzy[987] Generate and index test messages.
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9101
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN SASL-IR] debian Cyrus IMAP 3.0.6 server ready
S: * CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE
S: 1 OK Completed
C: 2 login cassandane "testpw"
=====> Instance[1873] authdaemon connection: cassandane testpw imap 
S: 2 OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY LOGINDISABLED XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in SESSIONID=<0352180101-17113-1525837938-2-17816169320432586029>
C: 3 select "inbox"
S: * 0 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
S: * OK [UIDVALIDITY 1525837939] Ok
S: * OK [UIDNEXT 1] Ok
S: * OK [HIGHESTMODSEQ 3] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 3 OK [READ-WRITE] Completed
C: 4 append inbox " 9-May-2018 13:52:18 +1000" {958}
S: + go ahead
C: Return-Path: <Hannah.Jones@gmail.com>
Received: from gateway (gateway.vmtom.com [10.0.0.1])
	by ahost (ahost.vmtom.com[10.0.0.2]); Wed, 09 May 2018 13:52:18 +1000
Received: from mail.gmail.com (mail.gmail.com [192.168.0.1])
	by gateway.vmtom.com (gateway.vmtom.com [10.0.0.1]); Wed, 09 May 2018 13:52:18 +1000
Mime-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Subject: [plumbing] Re: log server v0 live
From: Hannah V. Jones <Hannah.Jones@gmail.com>
Message-ID: <fake.1525837938.15679@gmail.com>
Date: Wed, 09 May 2018 13:52:18 +1000
To: Test User <test@vmtom.com>
X-Cassandane-Unique: 6dc69b48b2fe097c52f0b179f2efbdfe249ebdca

Test1 body with some long text and there is even more and more and more and more and more and more and more and more and more and some text and more and more and and more and more and more and more and more and more and almost at the end some other text that is a match C: 
S: * 1 EXISTS
S: * 1 RECENT
S: 4 OK [APPENDUID 1525837939 1] Completed
C: 5 unselect
S: 5 OK Completed
C: 6 select "inbox"
S: * 1 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
S: * OK [UNSEEN 1] Ok
S: * OK [UIDVALIDITY 1525837939] Ok
S: * OK [UIDNEXT 2] Ok
S: * OK [HIGHESTMODSEQ 4] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 6 OK [READ-WRITE] Completed
C: 7 append inbox " 9-May-2018 13:52:18 +1000" {682}
S: + go ahead
C: Return-Path: <ekb@hotmail.com>
Received: from gateway (gateway.vmtom.com [10.0.0.1])
	by ahost (ahost.vmtom.com[10.0.0.2]); Wed, 09 May 2018 13:52:18 +1000
Received: from mail.hotmail.com (mail.hotmail.com [192.168.0.1])
	by gateway.vmtom.com (gateway.vmtom.com [10.0.0.1]); Wed, 09 May 2018 13:52:18 +1000
Mime-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Subject: test2
From: Emily K. Brown <ekb@hotmail.com>
Message-ID: <fake.1525837938.47065@hotmail.com>
Date: Wed, 09 May 2018 13:52:18 +1000
To: Test User <test@vmtom.com>
X-Cassandane-Unique: 0f1829d303ac7009233bd8c1ba8f245684fbe9a7

Test2 body with some other textC: 
S: * 2 EXISTS
S: * 1 RECENT
S: 7 OK [APPENDUID 1525837939 2] Completed
=====> Instance[473] Found binary squatter in /dev/shm/cyrus/main/sbin
=====> Instance[1595] Running: "/dev/shm/cyrus/main/sbin/squatter" "-C" "/dev/shm/cass/0352180101/conf/imapd.conf"
0352180101/squatter[17114]: indexing mailboxes
0352180101/squatter[17114]: indexing mailbox user.cassandane... 
0352180101/squatter[17114]: Xapian committed 2 updates in 0.000178 sec
0352180101/squatter[17114]: done indexing mailboxes
=====> Cyrus::SearchFuzzy[1003] Select INBOX
C: 8 select "INBOX"
S: * OK [CLOSED] Ok
S: * 2 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
S: * OK [UNSEEN 1] Ok
S: * OK [UIDVALIDITY 1525837939] Ok
S: * OK [UIDNEXT 3] Ok
S: * OK [HIGHESTMODSEQ 5] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 8 OK [READ-WRITE] Completed
C: 9 search 1:* NOT DELETED
S: * SEARCH 1 2
S: 9 OK Completed (2 msgs in 0.000 secs)
=====> Cyrus::SearchFuzzy[1008] SEARCH for FUZZY snippets
C: 10 search fuzzy text servers
S: * SEARCH 1
S: 10 OK Completed (1 msgs in 0.001 secs)
C: 11 xsnippets ((inbox 1525837939 (1))) utf-8 (fuzzy text servers)
S: * SNIPPET "INBOX" 1525837939 1 SUBJECT "plumbing] Re: log <b>server</b> v0 live"
S: * SNIPPET "INBOX" 1525837939 1 LISTID "plumbing] Re: log <b>server</b> v0 live...[plumbing] Re: log <b>server</b> v0 live"
S: 11 OK Completed (in 0.001 secs)
=====> Cyrus::TestCase[679] Beginning tear_down
C: 12 logout
S: * BYE LOGOUT received
S: 12 OK Completed
A: Release socket, fileno=10
=====> Instance[1318] stop
=====> Instance[1280] _stop_pid: sending signal 15 to 17109
=====> Util::Wait[75] Waited 0.010937 sec for unknown condition
=====> Instance[1062] killing smtpd 17100
2018/05/09-13:52:18 Server closing!
=====> Instance[950] killing saslauthd 17104
=====> Instance[1062] killing smtpd 17100
=====> Instance[977] killing notifyd 17105
=====> Instance[1062] killing smtpd 17100
=====> Instance[950] killing saslauthd 17104
=====> Cyrus::TestCase[724] ---------- END test_search_subjectsnippet ----------
=====> Daemon[385] checking for stray processes on ports: 9100 9101
Cyrus::SearchFuzzy.search_subjectsnippet                                [FAILED]

Time:  0 wallclock secs ( 0.11 usr  0.01 sys +  0.14 cusr  0.08 csys =  0.34 CPU)

!!!FAILURES!!!
Test Results:
Run: 1, Failures: 1, Errors: 0

There was 1 failure:
1) test_search_subjectsnippet(Cassandane::Cyrus::SearchFuzzy)
 plumbing] Re: log <b>server</b> v0 live didn't match /(?^:^\[plumbing\])/ at Cassandane/Cyrus/SearchFuzzy.pm line 1019.
	Cassandane::Cyrus::SearchFuzzy::test_search_subjectsnippet(Cassandane::Cyrus::SearchFuzzy=HASH(0x55a0d9e70118)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 75
	[...framework calls elided...]

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_search_subjectsnippet ----------
=====> Instance[1076] start main instance for test test_search_subjectsnippet: basedir /dev/shm/cass/0352180101
=====> Instance[1059] started smtpd as 17100
=====> Instance[473] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[473] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1595] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/0352180101/conf/imapd.conf"
2018/05/09-13:52:18 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(17100)
Resolved [localhost]:9100 to [::1]:9100, IPv6
Resolved [localhost]:9100 to [127.0.0.1]:9100, IPv4
Binding to TCP port 9100 on host ::1 with IPv6
Binding to TCP port 9100 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[473] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[473] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[947] started saslauthd for /dev/shm/cass/0352180101 as 17104
=====> Instance[1858] opening socket /dev/shm/cass/0352180101/run/mux
=====> Instance[974] started notifyd for /dev/shm/cass/0352180101 as 17105
=====> Instance[890] _start_master: logging to /dev/shm/cass/0352180101/conf/master.log
=====> Instance[473] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1595] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/0352180101/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/0352180101/run/master.pid" "-d" "-M" "/dev/shm/cass/0352180101/conf/cyrus.conf" "-L" "/dev/shm/cass/0352180101/conf/master.log"
=====> Instance[899] _start_master: waiting for PID file
=====> Instance[902] _start_master: PID file present and correct
=====> Instance[914] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9101
=====> Util::Wait[75] Waited 0.023434 sec for 127.0.0.1:9101 to be in LISTEN state
=====> Instance[925] _start_master: all services listening
=====> Instance[1001] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9101
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN SASL-IR] debian Cyrus IMAP 3.0.6 server ready
S: * CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE
S: 1 OK Completed
C: 2 login admin "testpw"
=====> Instance[1873] authdaemon connection: admin testpw imap 
S: 2 OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY LOGINDISABLED XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in SESSIONID=<0352180101-17113-1525837938-1-6308073221863479862>
C: 3 create user.cassandane
S: 3 OK Completed
C: 4 setacl user.cassandane admin lrswipkxtecdan
S: 4 OK Completed
C: 5 setacl user.cassandane cassandane lrswipkxtecdn
S: 5 OK Completed
C: 6 setacl user.cassandane anyone p
S: 6 OK Completed
A: is_open test
A: is_open test received timeout, still open
C: 7 logout
S: * BYE LOGOUT received
S: 7 OK Completed
A: Release socket, fileno=10
=====> Instance[1111] started main instance for test test_search_subjectsnippet: cyrus version 3.0.6
=====> Cyrus::TestCase[572] Calling test function
=====> Cyrus::SearchFuzzy[76] Xapian flavor 'cyruslibs' detected.

=====> Cyrus::SearchFuzzy[987] Generate and index test messages.
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9101
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN SASL-IR] debian Cyrus IMAP 3.0.6 server ready
S: * CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE
S: 1 OK Completed
C: 2 login cassandane "testpw"
=====> Instance[1873] authdaemon connection: cassandane testpw imap 
S: 2 OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SEARCH=FUZZY SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES THREAD=REFS ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS LIST-METADATA WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE DIGEST=SHA1 X-REPLICATION URLAUTH URLAUTH=BINARY LOGINDISABLED XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in SESSIONID=<0352180101-17113-1525837938-2-17816169320432586029>
C: 3 select "inbox"
S: * 0 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
S: * OK [UIDVALIDITY 1525837939] Ok
S: * OK [UIDNEXT 1] Ok
S: * OK [HIGHESTMODSEQ 3] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 3 OK [READ-WRITE] Completed
C: 4 append inbox " 9-May-2018 13:52:18 +1000" {958}
S: + go ahead
C: Return-Path: <Hannah.Jones@gmail.com>
Received: from gateway (gateway.vmtom.com [10.0.0.1])
	by ahost (ahost.vmtom.com[10.0.0.2]); Wed, 09 May 2018 13:52:18 +1000
Received: from mail.gmail.com (mail.gmail.com [192.168.0.1])
	by gateway.vmtom.com (gateway.vmtom.com [10.0.0.1]); Wed, 09 May 2018 13:52:18 +1000
Mime-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Subject: [plumbing] Re: log server v0 live
From: Hannah V. Jones <Hannah.Jones@gmail.com>
Message-ID: <fake.1525837938.15679@gmail.com>
Date: Wed, 09 May 2018 13:52:18 +1000
To: Test User <test@vmtom.com>
X-Cassandane-Unique: 6dc69b48b2fe097c52f0b179f2efbdfe249ebdca

Test1 body with some long text and there is even more and more and more and more and more and more and more and more and more and some text and more and more and and more and more and more and more and more and more and almost at the end some other text that is a match C: 
S: * 1 EXISTS
S: * 1 RECENT
S: 4 OK [APPENDUID 1525837939 1] Completed
C: 5 unselect
S: 5 OK Completed
C: 6 select "inbox"
S: * 1 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
S: * OK [UNSEEN 1] Ok
S: * OK [UIDVALIDITY 1525837939] Ok
S: * OK [UIDNEXT 2] Ok
S: * OK [HIGHESTMODSEQ 4] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 6 OK [READ-WRITE] Completed
C: 7 append inbox " 9-May-2018 13:52:18 +1000" {682}
S: + go ahead
C: Return-Path: <ekb@hotmail.com>
Received: from gateway (gateway.vmtom.com [10.0.0.1])
	by ahost (ahost.vmtom.com[10.0.0.2]); Wed, 09 May 2018 13:52:18 +1000
Received: from mail.hotmail.com (mail.hotmail.com [192.168.0.1])
	by gateway.vmtom.com (gateway.vmtom.com [10.0.0.1]); Wed, 09 May 2018 13:52:18 +1000
Mime-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Subject: test2
From: Emily K. Brown <ekb@hotmail.com>
Message-ID: <fake.1525837938.47065@hotmail.com>
Date: Wed, 09 May 2018 13:52:18 +1000
To: Test User <test@vmtom.com>
X-Cassandane-Unique: 0f1829d303ac7009233bd8c1ba8f245684fbe9a7

Test2 body with some other textC: 
S: * 2 EXISTS
S: * 1 RECENT
S: 7 OK [APPENDUID 1525837939 2] Completed
=====> Instance[473] Found binary squatter in /dev/shm/cyrus/main/sbin
=====> Instance[1595] Running: "/dev/shm/cyrus/main/sbin/squatter" "-C" "/dev/shm/cass/0352180101/conf/imapd.conf"
0352180101/squatter[17114]: indexing mailboxes
0352180101/squatter[17114]: indexing mailbox user.cassandane... 
0352180101/squatter[17114]: Xapian committed 2 updates in 0.000178 sec
0352180101/squatter[17114]: done indexing mailboxes
=====> Cyrus::SearchFuzzy[1003] Select INBOX
C: 8 select "INBOX"
S: * OK [CLOSED] Ok
S: * 2 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
S: * OK [UNSEEN 1] Ok
S: * OK [UIDVALIDITY 1525837939] Ok
S: * OK [UIDNEXT 3] Ok
S: * OK [HIGHESTMODSEQ 5] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 8 OK [READ-WRITE] Completed
C: 9 search 1:* NOT DELETED
S: * SEARCH 1 2
S: 9 OK Completed (2 msgs in 0.000 secs)
=====> Cyrus::SearchFuzzy[1008] SEARCH for FUZZY snippets
C: 10 search fuzzy text servers
S: * SEARCH 1
S: 10 OK Completed (1 msgs in 0.001 secs)
C: 11 xsnippets ((inbox 1525837939 (1))) utf-8 (fuzzy text servers)
S: * SNIPPET "INBOX" 1525837939 1 SUBJECT "plumbing] Re: log <b>server</b> v0 live"
S: * SNIPPET "INBOX" 1525837939 1 LISTID "plumbing] Re: log <b>server</b> v0 live...[plumbing] Re: log <b>server</b> v0 live"
S: 11 OK Completed (in 0.001 secs)
=====> Cyrus::TestCase[679] Beginning tear_down
C: 12 logout
S: * BYE LOGOUT received
S: 12 OK Completed
A: Release socket, fileno=10
=====> Instance[1318] stop
=====> Instance[1280] _stop_pid: sending signal 15 to 17109
=====> Util::Wait[75] Waited 0.010937 sec for unknown condition
=====> Instance[1062] killing smtpd 17100
2018/05/09-13:52:18 Server closing!
=====> Instance[950] killing saslauthd 17104
=====> Instance[1062] killing smtpd 17100
=====> Instance[977] killing notifyd 17105
=====> Instance[1062] killing smtpd 17100
=====> Instance[950] killing saslauthd 17104
=====> Cyrus::TestCase[724] ---------- END test_search_subjectsnippet ----------
=====> Daemon[385] checking for stray processes on ports: 9100 9101

Test was not successful.
@elliefm elliefm added the 3.0 affects 3.0 label May 9, 2018
@rsto
Copy link
Member

rsto commented May 9, 2018

This happens if Cyrus didn't get built with the cyruslibs Xapian fork. It's missing this commit: cyrusimap/xapian@7d4b25e

I've a pull request for Xapian upstream open: xapian/xapian#180

Probably the best to do is that I add a check for the cyruslibs flavour and disable that Cassandane test for standard upstream Xapian builds.

@elliefm
Copy link
Contributor Author

elliefm commented May 11, 2018

In this case though, 3.0 and master are both being built with the same Xapian installation, which is the cyruslibs version. So it seems odd that 3.0 would behave differently??

@elliefm
Copy link
Contributor Author

elliefm commented May 11, 2018

... though that Xapian commit seems to be exactly the thing that's going on. Weird?

@rsto
Copy link
Member

rsto commented May 11, 2018

Meh, I just never pushed this to 3.0. This is what's missing: 2483738

Will you cherry-pick or should I merge this in?

@elliefm
Copy link
Contributor Author

elliefm commented May 14, 2018

Aha! I'll cherry pick that in, thanks :)

@elliefm elliefm closed this as completed May 14, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@rsto rsto

@elliefm elliefm

Labels
3.0 affects 3.0
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@rsto @elliefm