Cyrus IMAP 3.2.0 released

Marco falon at ruparpiemonte.it
Wed May 6 11:00:54 EDT 2020


Hello,

  I list here other failed tests in my environment. I thank you very 
much if you could give me some hints.

5) ImapTest.append-binary
  Boolean assertion failed at 
/usr/share/perl5/vendor_perl/Test/Unit/Exception.pm line 13.
 
Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x561369cdc520), 
"-package", "Cassandane::Cyrus::ImapTest", "-file", 
"Cassandane/Cyrus/ImapTest.pm", "-line", 187, "-object", ...) called at 
/usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 85
 
Test::Unit::Assert::do_assertion(Cassandane::Cyrus::ImapTest=HASH(0x561366c121d8), 
Test::Unit::Assertion::Boolean=SCALAR(0x561369df51b0), 
"Cassandane::Cyrus::ImapTest", "Cassandane/Cyrus/ImapTest.pm", 187) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 19
 
Test::Unit::Assert::assert(Cassandane::Cyrus::ImapTest=HASH(0x561366c121d8), 
0) called at Cassandane/Cyrus/ImapTest.pm line 187
 
Cassandane::Cyrus::ImapTest::run_test(Cassandane::Cyrus::ImapTest=HASH(0x561366c121d8)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 61
 
Test::Unit::TestCase::run_bare(Cassandane::Cyrus::ImapTest=HASH(0x561366c121d8)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 103
         Test::Unit::Result::__ANON__() called at 
/usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 119
 
Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Cyrus::ImapTest=HASH(0x561366c121d8), CODE(0x561369d7bde0)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 107
 
Test::Unit::Result::run(Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Cyrus::ImapTest=HASH(0x561366c121d8)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 51
 
Test::Unit::TestCase::run(Cassandane::Cyrus::ImapTest=HASH(0x561366c121d8), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestSuite.pm line 278
 
Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x561366bfc700), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
Cassandane/Unit/TestPlan.pm line 769
 
Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
HASH(0x561369bdddf0), Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0), 0) called at 
Cassandane/Unit/TestPlan.pm line 885
         Cassandane::Unit::TestPlan::__ANON__(HASH(0x561369bdddf0)) 
called at Cassandane/Unit/TestPlan.pm line 205
 
Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x561364e654b8)) 
called at Cassandane/Unit/TestPlan.pm line 165
 
Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x561364e654b8)) 
called at Cassandane/Unit/TestPlan.pm line 310
 
Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x561364e654e8)) 
called at Cassandane/Unit/TestPlan.pm line 889
 
Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestRunner.pm line 54
 
Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0), 
Cassandane::Unit::TestPlan=HASH(0x561364e51380), 0) called at 
./testrunner.pl line 132
         main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
GLOB(0x561364e51368)) called at ./testrunner.pl line 315

Annotations:
=====> Cyrus::TestCase::set_up[90] ---------- BEGIN test_append-binary 
----------
=====> Instance::start[659] start main instance for test 
test_append-binary: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185
2020/05/06-13:01:00 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(26110)
Resolved [localhost]:19118 to [::1]:19118, IPv6
Resolved [localhost]:19118 to [127.0.0.1]:19118, IPv4
Binding to TCP port 19118 on host ::1 with IPv6
Binding to TCP port 19118 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 26110
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185 as 26118
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185/conf/master.log"
=====> Instance::_fork_command[1562] child pid=26120
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19119
=====> Util::Wait::timed_wait[909] Waited 0.182261 sec for 
127.0.0.1:19119 to be in LISTEN state
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::create_user[1175] create user cassandane
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19119
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460185-1588762861-26142-1-3258557518456563356>
C: 3 create user/cassandane
S: 3 OK [MAILBOXID (1c8aefad-c171-4fb6-9e15-ea4a9085763b)] 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=57
=====> Instance::start[659] started main instance for test 
test_append-binary: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::set_up[90] (test_append-binary) Calling test 
function
=====> Instance::create_user[92] create user user2
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19119
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460185-1588762862-26142-1-16054340835693561001>
C: 3 create user/user2
S: 3 OK [MAILBOXID (de6f3a91-e4ce-4a28-9940-102e60347f81)] Completed
C: 4 setacl user/user2 admin lrswipkxtecdan
S: 4 OK Completed
C: 5 setacl user/user2 user2 lrswipkxtecdn
S: 5 OK Completed
C: 6 setacl user/user2 anyone p
S: 6 OK Completed
C: 7 create user/user2/imaptest
S: 7 OK [MAILBOXID (ce6c47eb-fe09-42b4-aadf-cfb7176b105c)] Completed
C: 8 setacl user/user2/imaptest admin lrswipkxtecdan
S: 8 OK Completed
C: 9 setacl user/user2/imaptest user2 lrswipkxtecdn
S: 9 OK Completed
C: 10 setacl user/user2/imaptest anyone p
S: 10 OK Completed
A: is_open test
A: is_open test received timeout, still open
C: 11 logout
S: * BYE LOGOUT received
S: 11 OK Completed
A: Release socket, fileno=57
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane-9c2edd4f78391c85464f42a03b57cfa882d1aba9/imaptest/src/imaptest" 
"host=127.0.0.1" "port=19119" "user=cassandane" "user2=user2" 
"pass=testpw" "rawlog" 
"test=/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane-9c2edd4f78391c85464f42a03b57cfa882d1aba9/imaptest/src/tests/append-binary"
=====> Instance::_fork_command[1562] child pid=26144
=====> Instance::_fork_command[1562] setting core size limit to 104857600
1 test groups: 1 failed, 0 skipped due to missing capabilities
base protocol: 0/0 individual commands failed
extensions: 3/4 individual commands failed
=====> Cyrus::ImapTest::run_test[61] (test_append-binary) Error: 
cassandane[1]: BAD reply for command: fetch 1 (binary.size[text] 
binary.peek[text]): 1.8 BAD Invalid binary section

=====> Cyrus::ImapTest::run_test[61] (test_append-binary) *** Test 
append-binary command 4/5 (line 35)

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - failed: 
Expected tagged reply 'ok', got 'BAD Invalid binary section'

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - Command 
(tag 1.8): fetch 1 (binary.size[text] binary.peek[text])

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)

=====> Cyrus::ImapTest::run_test[61] (test_append-binary) *** Test 
append-binary command 4/5 (line 35)

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - failed: 
Missing 1 untagged replies (0 mismatches)

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - first 
unexpanded: 1 fetch ($!unordered=2 binary.size[text] 7 binary[text] {0}

=====> Cyrus::ImapTest::run_test[61] (test_append-binary) )

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - first 
expanded: 1 fetch ( binary.size[text] 7 binary[text] {0}

=====> Cyrus::ImapTest::run_test[61] (test_append-binary) )

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - best match: 
1 FETCH (BODY[TEXT] "AC3kCg0KCg==

=====> Cyrus::ImapTest::run_test[61] (test_append-binary) ")

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - Command: 
fetch 1 (binary.size[text] binary.peek[text])

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)

=====> Cyrus::ImapTest::run_test[61] (test_append-binary) *** Test 
append-binary command 5/5 (line 0)

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - failed: 
Unexpected disconnection

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)  - Command: logout

=====> Cyrus::ImapTest::run_test[61] (test_append-binary)

============> rawlog.1 <=============
1588762862.478914 I: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE 
AUTH=PLAIN AUTH=LOGIN SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  server 
ready
1588762862.478958 O: 1.1 LOGIN "cassandane" "testpw"
1588762862.566315 I: 1.1 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 
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 STATUS=SIZE OBJECTID 
SAVEDATE X-CREATEDMODSEQ PREVIEW=FUZZY URLAUTH URLAUTH=BINARY 
LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460185-1588762862-26142-2-8474523257771899166>
1588762862.566403 O: 1.2 LIST "" "imaptest*"
1588762862.566408 O: 1.3 LSUB "" "imaptest*"
1588762862.570184 I: 1.2 OK Completed (0.000 secs)
1588762862.612923 I: 1.3 OK Completed (0.000 secs)
1588762862.612971 O: 1.4 CREATE "imaptest"
1588762862.652168 I: 1.4 OK [MAILBOXID 
(a4560844-7882-4c7d-bb30-14173427338f)] Completed
1588762862.652221 O: 1.5 append imaptest ~{165+}
1588762862.652221 O: From: user at domain.org
1588762862.652221 O: Date: Sat, 24 Mar 2007 23:00:00 +0200
1588762862.652221 O: Mime-Version: 1.0
1588762862.652221 O: Content-Type: application/octet-stream
1588762862.652221 O: Content-Transfer-Encoding: binary
1588762862.652221 O:
1588762862.652221 O: -▒
1588762862.652221 O:
1588762862.652221 O:
1588762862.652229 O:
1588762862.770922 I: 1.5 OK [APPENDUID 1588762863 1] Completed
1588762862.770982 O: 1.6 select imaptest
1588762862.782930 I: * 1 EXISTS
1588762862.782930 I: * 1 RECENT
1588762862.782930 I: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
1588762862.782930 I: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft 
\Deleted \Seen \*)] Ok
1588762862.782930 I: * OK [UNSEEN 1] Ok
1588762862.782930 I: * OK [UIDVALIDITY 1588762863] Ok
1588762862.782930 I: * OK [UIDNEXT 2] Ok
1588762862.782930 I: * OK [HIGHESTMODSEQ 2] Ok
1588762862.782930 I: * OK [URLMECH INTERNAL] Ok
1588762862.782930 I: * OK [ANNOTATIONS 65536] Ok
1588762862.782930 I: 1.6 OK [READ-WRITE] Completed
1588762862.783033 O: 1.7 fetch 1 (body.peek[text])
1588762862.794924 I: * 1 FETCH (BODY[TEXT] {14}
1588762862.794924 I: AC3kCg0KCg==
1588762862.794924 I: )
1588762862.794924 I: 1.7 OK Completed (0.000 sec)
1588762862.795005 O: 1.8 fetch 1 (binary.size[text] binary.peek[text])
1588762862.808922 I: 1.8 BAD Invalid binary section
=====> Cyrus::TestCase::tear_down[98] (test_append-binary) Beginning 
tear_down
=====> Instance::stop[773] stop main instance for test 
test_append-binary: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460185
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 26122
=====> Util::Wait::timed_wait[1376] Waited 0.035899 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 26110
2020/05/06-13:01:02 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 26118
=====> Instance::__ANON__[1459] killing smtpd 26110
=====> Cyrus::TestCase::tear_down[98] ---------- END test_append-binary 
----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19118 19119

6) ImapTest.fetch-binary-mime
  Boolean assertion failed at 
/usr/share/perl5/vendor_perl/Test/Unit/Exception.pm line 13.
 
Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x561369e4f2f8), 
"-package", "Cassandane::Cyrus::ImapTest", "-file", 
"Cassandane/Cyrus/ImapTest.pm", "-line", 187, "-object", ...) called at 
/usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 85
 
Test::Unit::Assert::do_assertion(Cassandane::Cyrus::ImapTest=HASH(0x561366c20f38), 
Test::Unit::Assertion::Boolean=SCALAR(0x56136245d560), 
"Cassandane::Cyrus::ImapTest", "Cassandane/Cyrus/ImapTest.pm", 187) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 19
 
Test::Unit::Assert::assert(Cassandane::Cyrus::ImapTest=HASH(0x561366c20f38), 
0) called at Cassandane/Cyrus/ImapTest.pm line 187
 
Cassandane::Cyrus::ImapTest::run_test(Cassandane::Cyrus::ImapTest=HASH(0x561366c20f38)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 61
 
Test::Unit::TestCase::run_bare(Cassandane::Cyrus::ImapTest=HASH(0x561366c20f38)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 103
         Test::Unit::Result::__ANON__() called at 
/usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 119
 
Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Cyrus::ImapTest=HASH(0x561366c20f38), CODE(0x561369c2f3b8)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 107
 
Test::Unit::Result::run(Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Cyrus::ImapTest=HASH(0x561366c20f38)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 51
 
Test::Unit::TestCase::run(Cassandane::Cyrus::ImapTest=HASH(0x561366c20f38), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestSuite.pm line 278
 
Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x561366bfc700), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
Cassandane/Unit/TestPlan.pm line 769
 
Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
HASH(0x561369d2fb68), Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0), 0) called at 
Cassandane/Unit/TestPlan.pm line 885
         Cassandane::Unit::TestPlan::__ANON__(HASH(0x561369d2fb68)) 
called at Cassandane/Unit/TestPlan.pm line 205
 
Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x561369471e50)) 
called at Cassandane/Unit/TestPlan.pm line 165
 
Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x561369471e50)) 
called at Cassandane/Unit/TestPlan.pm line 310
 
Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x561364e654e8)) 
called at Cassandane/Unit/TestPlan.pm line 889
 
Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestRunner.pm line 54
 
Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0), 
Cassandane::Unit::TestPlan=HASH(0x561364e51380), 0) called at 
./testrunner.pl line 132
         main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
GLOB(0x561364e51368)) called at ./testrunner.pl line 315

Annotations:
=====> Cyrus::TestCase::set_up[90] ---------- BEGIN 
test_fetch-binary-mime ----------
=====> Instance::start[659] start main instance for test 
test_fetch-binary-mime: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274
2020/05/06-13:01:16 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(26404)
Resolved [localhost]:19137 to [::1]:19137, IPv6
Resolved [localhost]:19137 to [127.0.0.1]:19137, IPv4
Binding to TCP port 19137 on host ::1 with IPv6
Binding to TCP port 19137 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 26404
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274 as 26419
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274/conf/master.log"
=====> Instance::_fork_command[1562] child pid=26421
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19138
=====> Util::Wait::timed_wait[909] Waited 0.143403 sec for 
127.0.0.1:19138 to be in LISTEN state
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::create_user[1175] create user cassandane
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19138
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460274-1588762877-26437-1-9714254449861085337>
C: 3 create user/cassandane
S: 3 OK [MAILBOXID (bb3ff27c-59d9-4f04-aa49-5053821cc52c)] 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=57
=====> Instance::start[659] started main instance for test 
test_fetch-binary-mime: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::set_up[90] (test_fetch-binary-mime) Calling test 
function
=====> Instance::create_user[92] create user user2
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19138
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460274-1588762877-26437-2-17948943078115582425>
C: 3 create user/user2
S: 3 OK [MAILBOXID (7ec65a1e-59c2-4914-a617-d2a8b9e3abe4)] Completed
C: 4 setacl user/user2 admin lrswipkxtecdan
S: 4 OK Completed
C: 5 setacl user/user2 user2 lrswipkxtecdn
S: 5 OK Completed
C: 6 setacl user/user2 anyone p
S: 6 OK Completed
C: 7 create user/user2/imaptest
S: 7 OK [MAILBOXID (36525e2d-67ad-413b-b3d7-812a55eed731)] Completed
C: 8 setacl user/user2/imaptest admin lrswipkxtecdan
S: 8 OK Completed
C: 9 setacl user/user2/imaptest user2 lrswipkxtecdn
S: 9 OK Completed
C: 10 setacl user/user2/imaptest anyone p
S: 10 OK Completed
A: is_open test
A: is_open test received timeout, still open
C: 11 logout
S: * BYE LOGOUT received
S: 11 OK Completed
A: Release socket, fileno=57
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane-9c2edd4f78391c85464f42a03b57cfa882d1aba9/imaptest/src/imaptest" 
"host=127.0.0.1" "port=19138" "user=cassandane" "user2=user2" 
"pass=testpw" "rawlog" 
"test=/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane-9c2edd4f78391c85464f42a03b57cfa882d1aba9/imaptest/src/tests/fetch-binary-mime"
=====> Instance::_fork_command[1562] child pid=26439
=====> Instance::_fork_command[1562] setting core size limit to 104857600
1 test groups: 1 failed, 0 skipped due to missing capabilities
base protocol: 0/0 individual commands failed
extensions: 3/3 individual commands failed
=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime) Error: 
cassandane[1]: BAD reply for command: fetch 1 (binary.size[text]): 1.9 
BAD Invalid binary section

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime) *** Test 
fetch-binary-mime command 3/29 (line 52)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - failed: 
Expected tagged reply 'ok', got 'BAD Invalid binary section'

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - Command 
(tag 1.9): fetch 1 (binary.size[text])

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime) *** Test 
fetch-binary-mime command 3/29 (line 52)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - failed: 
Missing 1 untagged replies (0 mismatches)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - first 
unexpanded: 1 fetch ($!unordered=2 binary.size[text] 466)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - first 
expanded: 1 fetch ( binary.size[text] 466)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - best match:

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - 
Command: fetch 1 (binary.size[text])

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime) *** Test 
fetch-binary-mime command 4/29 (line 55)

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - failed: 
Unexpected disconnection

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)  - 
Command: fetch 1 (binary.peek[text])

=====> Cyrus::ImapTest::run_test[61] (test_fetch-binary-mime)

============> rawlog.1 <=============
1588762877.516844 I: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE 
AUTH=PLAIN AUTH=LOGIN SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  server 
ready
1588762877.516939 O: 1.1 LOGIN "cassandane" "testpw"
1588762877.523118 I: 1.1 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 
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 STATUS=SIZE OBJECTID 
SAVEDATE X-CREATEDMODSEQ PREVIEW=FUZZY URLAUTH URLAUTH=BINARY 
LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460274-1588762877-26437-3-16401295678954551014>
1588762877.523230 O: 1.2 LIST "" "imaptest*"
1588762877.523240 O: 1.3 LSUB "" "imaptest*"
1588762877.524494 I: 1.2 OK Completed (0.000 secs)
1588762877.564167 I: 1.3 OK Completed (0.000 secs)
1588762877.564218 O: 1.4 CREATE "imaptest"
1588762877.612346 I: 1.4 OK [MAILBOXID 
(80a93f8f-2030-44b5-9927-84177e6fa363)] Completed
1588762877.612551 O: 1.5 APPEND "imaptest" "22-Feb-2008 17:06:23 +0100" 
{602+}
1588762877.612587 O: From: user at domain.org
1588762877.612587 O: Date: Sat, 24 Mar 2007 23:00:00 +0200
1588762877.612587 O: Mime-Version: 1.0
1588762877.612587 O: Content-Type: multipart/mixed; boundary="foo
1588762877.612587 O:  bar"
1588762877.612587 O:
1588762877.612587 O: Root MIME prologue
1588762877.612587 O:
1588762877.612587 O: --foo bar
1588762877.612587 O: Content-Type: text/x-myown; charset=us-ascii
1588762877.612587 O:
1588762877.612587 O: hello
1588762877.612587 O:
1588762877.612587 O: --foo bar
1588762877.612587 O: Content-Type: message/rfc822
1588762877.612587 O:
1588762877.612587 O: From: sub at domain.org
1588762877.612587 O: Date: Sun, 12 Aug 2012 12:34:56 +0300
1588762877.612587 O: Subject: submsg
1588762877.612587 O: Content-Type: multipart/alternative; boundary="sub1"
1588762877.612587 O:
1588762877.612587 O: Sub MIME prologue
1588762877.612587 O: --sub1
1588762877.612587 O: Content-Type: text/html
1588762877.612587 O:
1588762877.612587 O: <p>Hello world</p>
1588762877.612587 O:
1588762877.612587 O: --sub1
1588762877.612587 O: Content-Type: text/plain
1588762877.612587 O:
1588762877.612587 O: Hello another world
1588762877.612587 O:
1588762877.612587 O: --sub1--
1588762877.612587 O: Sub MIME epilogue
1588762877.612587 O:
1588762877.612587 O: --foo bar--
1588762877.612587 O: Root MIME epilogue
1588762877.612645 O:
1588762877.721632 I: 1.5 OK [APPENDUID 1588762878 1] Completed
1588762877.721682 O: 1.6 SELECT "imaptest"
1588762877.725959 I: * 1 EXISTS
1588762877.725959 I: * 1 RECENT
1588762877.725959 I: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
1588762877.725959 I: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft 
\Deleted \Seen \*)] Ok
1588762877.725959 I: * OK [UNSEEN 1] Ok
1588762877.725959 I: * OK [UIDVALIDITY 1588762878] Ok
1588762877.725959 I: * OK [UIDNEXT 2] Ok
1588762877.725959 I: * OK [HIGHESTMODSEQ 2] Ok
1588762877.725959 I: * OK [URLMECH INTERNAL] Ok
1588762877.725959 I: * OK [ANNOTATIONS 65536] Ok
1588762877.725959 I: 1.6 OK [READ-WRITE] Completed
1588762877.726007 O: 1.7 fetch 1 (binary.peek[])
1588762877.726454 I: * 1 FETCH (BINARY[] {602}
1588762877.726454 I: From: user at domain.org
1588762877.726454 I: Date: Sat, 24 Mar 2007 23:00:00 +0200
1588762877.726454 I: Mime-Version: 1.0
1588762877.726454 I: Content-Type: multipart/mixed; boundary="foo
1588762877.726454 I:  bar"
1588762877.726454 I:
1588762877.726454 I: Root MIME prologue
1588762877.726454 I:
1588762877.726454 I: --foo bar
1588762877.726454 I: Content-Type: text/x-myown; charset=us-ascii
1588762877.726454 I:
1588762877.726454 I: hello
1588762877.726454 I:
1588762877.726454 I: --foo bar
1588762877.726454 I: Content-Type: message/rfc822
1588762877.726454 I:
1588762877.726454 I: From: sub at domain.org
1588762877.726454 I: Date: Sun, 12 Aug 2012 12:34:56 +0300
1588762877.726454 I: Subject: submsg
1588762877.726454 I: Content-Type: multipart/alternative; boundary="sub1"
1588762877.726454 I:
1588762877.726454 I: Sub MIME prologue
1588762877.726454 I: --sub1
1588762877.726454 I: Content-Type: text/html
1588762877.726454 I:
1588762877.726454 I: <p>Hello world</p>
1588762877.726454 I:
1588762877.726454 I: --sub1
1588762877.726454 I: Content-Type: text/plain
1588762877.726454 I:
1588762877.726454 I: Hello another world
1588762877.726454 I:
1588762877.726454 I: --sub1--
1588762877.726454 I: Sub MIME epilogue
1588762877.726454 I:
1588762877.726454 I: --foo bar--
1588762877.726454 I: Root MIME epilogue
1588762877.726454 I: )
1588762877.726454 I: 1.7 OK Completed (0.000 sec)
1588762877.726519 O: 1.8 fetch 1 (binary.size[])
1588762877.726935 I: * 1 FETCH (BINARY.SIZE[] 602)
1588762877.726935 I: 1.8 OK Completed (0.000 sec)
1588762877.726963 O: 1.9 fetch 1 (binary.size[text])
1588762877.727155 I: 1.9 BAD Invalid binary section
=====> Cyrus::TestCase::tear_down[98] (test_fetch-binary-mime) Beginning 
tear_down
=====> Instance::stop[773] stop main instance for test 
test_fetch-binary-mime: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460274
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 26423
=====> Util::Wait::timed_wait[1376] Waited 0.023258 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 26404
2020/05/06-13:01:17 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 26419
=====> Instance::__ANON__[1459] killing smtpd 26404
=====> Cyrus::TestCase::tear_down[98] ---------- END 
test_fetch-binary-mime ----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19137 19138

7) ImapTest.urlauth-binary
  Boolean assertion failed at 
/usr/share/perl5/vendor_perl/Test/Unit/Exception.pm line 13.
 
Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x561369d7e688), 
"-package", "Cassandane::Cyrus::ImapTest", "-file", 
"Cassandane/Cyrus/ImapTest.pm", "-line", 187, "-object", ...) called at 
/usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 85
 
Test::Unit::Assert::do_assertion(Cassandane::Cyrus::ImapTest=HASH(0x561366c2f178), 
Test::Unit::Assertion::Boolean=SCALAR(0x561369d89ab8), 
"Cassandane::Cyrus::ImapTest", "Cassandane/Cyrus/ImapTest.pm", 187) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 19
 
Test::Unit::Assert::assert(Cassandane::Cyrus::ImapTest=HASH(0x561366c2f178), 
0) called at Cassandane/Cyrus/ImapTest.pm line 187
 
Cassandane::Cyrus::ImapTest::run_test(Cassandane::Cyrus::ImapTest=HASH(0x561366c2f178)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 61
 
Test::Unit::TestCase::run_bare(Cassandane::Cyrus::ImapTest=HASH(0x561366c2f178)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 103
         Test::Unit::Result::__ANON__() called at 
/usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 119
 
Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Cyrus::ImapTest=HASH(0x561366c2f178), CODE(0x561369d8a0a0)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/Result.pm line 107
 
Test::Unit::Result::run(Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Cyrus::ImapTest=HASH(0x561366c2f178)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 51
 
Test::Unit::TestCase::run(Cassandane::Cyrus::ImapTest=HASH(0x561366c2f178), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestSuite.pm line 278
 
Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x561366bfc700), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
Cassandane/Unit/TestPlan.pm line 769
 
Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
HASH(0x561369d11010), Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0), 0) called at 
Cassandane/Unit/TestPlan.pm line 885
         Cassandane::Unit::TestPlan::__ANON__(HASH(0x561369d11010)) 
called at Cassandane/Unit/TestPlan.pm line 205
 
Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x561364e654b8)) 
called at Cassandane/Unit/TestPlan.pm line 165
 
Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x561364e654b8)) 
called at Cassandane/Unit/TestPlan.pm line 310
 
Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x561364e654e8)) 
called at Cassandane/Unit/TestPlan.pm line 889
 
Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
Test::Unit::Result=HASH(0x561364e650f8), 
Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0)) called at 
/usr/share/perl5/vendor_perl/Test/Unit/TestRunner.pm line 54
 
Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x561364e64ed0), 
Cassandane::Unit::TestPlan=HASH(0x561364e51380), 0) called at 
./testrunner.pl line 132
         main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x561364e51380), 
GLOB(0x561364e51368)) called at ./testrunner.pl line 315

Annotations:
=====> Cyrus::TestCase::set_up[90] ---------- BEGIN test_urlauth-binary 
----------
=====> Instance::start[659] start main instance for test 
test_urlauth-binary: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6
2020/05/06-13:02:19 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(27719)
Resolved [localhost]:19104 to [::1]:19104, IPv6
Resolved [localhost]:19104 to [127.0.0.1]:19104, IPv4
Binding to TCP port 19104 on host ::1 with IPv6
Binding to TCP port 19104 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 27719
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6 as 27737
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6/conf/master.log"
=====> Instance::_fork_command[1562] child pid=27739
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19105
=====> Util::Wait::timed_wait[909] Waited 0.091447 sec for 
127.0.0.1:19105 to be in LISTEN state
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::create_user[1175] create user cassandane
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19105
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<10534601A6-1588762940-27748-1-6909409219667287127>
C: 3 create user/cassandane
S: 3 OK [MAILBOXID (67291535-cd3a-4af9-b854-87b34c1c5401)] 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=57
=====> Instance::start[659] started main instance for test 
test_urlauth-binary: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::set_up[90] (test_urlauth-binary) Calling test 
function
=====> Instance::create_user[92] create user user2
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19105
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<10534601A6-1588762940-27748-2-8160656956801725156>
C: 3 create user/user2
S: 3 OK [MAILBOXID (000e2a3f-cc73-42f5-aea6-98c65c9ebc5e)] Completed
C: 4 setacl user/user2 admin lrswipkxtecdan
S: 4 OK Completed
C: 5 setacl user/user2 user2 lrswipkxtecdn
S: 5 OK Completed
C: 6 setacl user/user2 anyone p
S: 6 OK Completed
C: 7 create user/user2/imaptest
S: 7 OK [MAILBOXID (ba86ac07-7fb9-4f1a-859d-8f5ac7c1f619)] Completed
C: 8 setacl user/user2/imaptest admin lrswipkxtecdan
S: 8 OK Completed
C: 9 setacl user/user2/imaptest user2 lrswipkxtecdn
S: 9 OK Completed
C: 10 setacl user/user2/imaptest anyone p
S: 10 OK Completed
A: is_open test
A: is_open test received timeout, still open
C: 11 logout
S: * BYE LOGOUT received
S: 11 OK Completed
A: Release socket, fileno=57
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane-9c2edd4f78391c85464f42a03b57cfa882d1aba9/imaptest/src/imaptest" 
"host=127.0.0.1" "port=19105" "user=cassandane" "user2=user2" 
"pass=testpw" "rawlog" 
"test=/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane-9c2edd4f78391c85464f42a03b57cfa882d1aba9/imaptest/src/tests/urlauth-binary"
=====> Instance::_fork_command[1562] child pid=27749
=====> Instance::_fork_command[1562] setting core size limit to 104857600
1 test groups: 1 failed, 0 skipped due to missing capabilities
base protocol: 0/0 individual commands failed
extensions: 3/16 individual commands failed
=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) *** Test 
urlauth-binary command 9/16 (line 22)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - failed: 
Missing 1 untagged replies (1 mismatches)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - first 
unexpanded: URLFETCH $mail_url1 (binary {390}

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) From: 
sub at domain.org

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Date: Sun, 12 
Aug 2012 12:34:56 +0300

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Subject: submsg

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
multipart/alternative; boundary="sub1"

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME prologue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1--

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME epilogue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) )

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - first 
expanded: URLFETCH 
imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane:internal:0011b22d85d895a3b5ee1cec0839348c1b9c38e90a 
(binary {390}

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) From: 
sub at domain.org

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Date: Sun, 12 
Aug 2012 12:34:56 +0300

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Subject: submsg

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
multipart/alternative; boundary="sub1"

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME prologue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1--

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME epilogue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) )

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - best 
match: URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane:internal:0011b22d85d895a3b5ee1cec0839348c1b9c38e90a" 
(BINARY "From: sub at domain.org

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Date: Sun, 12 
Aug 2012 12:34:56 +0300

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Subject: submsg

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
multipart/alternative; boundary=\"sub1\"

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME prologue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: base64

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) aGVs

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) bG8gd29y

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) bGQ=

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: base64

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)   aGVs

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  bG8g

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)    d29y

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)     bGQ=

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1--

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME epilogue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) ")

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - Command: 
URLFETCH ($mail_url1 binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) *** Test 
urlauth-binary command 13/16 (line 57)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - failed: 
Missing 1 untagged replies (1 mismatches)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - first 
unexpanded: URLFETCH $mail_url2 (BODYPARTSTRUCTURE ("message" "rfc822" 
NIL NIL NIL "7bit" 390 ("Sun, 12 Aug 2012 12:34:56 +0300" "submsg" ((NIL 
NIL "sub" "domain.org")) ((NIL NIL "sub" "domain.org")) ((NIL NIL "sub" 
"domain.org")) NIL NIL NIL NIL NIL) (("text" "x-myown" ("charset" 
"us-ascii") NIL NIL "base64" 11 0 NIL NIL NIL NIL) ("text" "x-myown" 
("charset" "us-ascii") NIL NIL "base64" 11 0 NIL NIL NIL NIL) 
"alternative" ("boundary" "sub1") NIL NIL NIL) 18 NIL NIL NIL NIL) 
binary {390}

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) From: 
sub at domain.org

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Date: Sun, 12 
Aug 2012 12:34:56 +0300

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Subject: submsg

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
multipart/alternative; boundary="sub1"

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME prologue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1--

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME epilogue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) )

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - first 
expanded: URLFETCH 
imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1;urlauth=user+cassandane:internal:005fd11034c1463087bb7c2730d1da10d179955576 
(BODYPARTSTRUCTURE ("message" "rfc822" NIL NIL NIL "7bit" 390 ("Sun, 12 
Aug 2012 12:34:56 +0300" "submsg" ((NIL NIL "sub" "domain.org")) ((NIL 
NIL "sub" "domain.org")) ((NIL NIL "sub" "domain.org")) NIL NIL NIL NIL 
NIL) (("text" "x-myown" ("charset" "us-ascii") NIL NIL "base64" 11 0 NIL 
NIL NIL NIL) ("text" "x-myown" ("charset" "us-ascii") NIL NIL "base64" 
11 0 NIL NIL NIL NIL) "alternative" ("boundary" "sub1") NIL NIL NIL) 18 
NIL NIL NIL NIL) binary {390}

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) From: 
sub at domain.org

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Date: Sun, 12 
Aug 2012 12:34:56 +0300

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Subject: submsg

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
multipart/alternative; boundary="sub1"

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME prologue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: binary

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1--

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME epilogue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) )

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - best 
match: URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1;urlauth=user+cassandane:internal:005fd11034c1463087bb7c2730d1da10d179955576" 
(BODYPARTSTRUCTURE ("MESSAGE" "RFC822" NIL NIL NIL "7BIT" 437 ("Sun, 12 
Aug 2012 12:34:56 +0300" "submsg" ((NIL NIL "sub" "domain.org")) ((NIL 
NIL "sub" "domain.org")) ((NIL NIL "sub" "domain.org")) NIL NIL NIL NIL 
NIL) (("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL "BASE64" 22 3 NIL 
NIL NIL NIL) ("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL "BASE64" 
47 5 NIL NIL NIL NIL) "ALTERNATIVE" ("BOUNDARY" "sub1") NIL NIL NIL) 26 
NIL NIL NIL NIL)) (BINARY "From: sub at domain.org

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Date: Sun, 12 
Aug 2012 12:34:56 +0300

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Subject: submsg

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
multipart/alternative; boundary=\"sub1\"

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME prologue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: base64

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) aGVs

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) bG8gd29y

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) bGQ=

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Content-Type: 
text/x-myown; charset=us-ascii

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) 
Content-Transfer-Encoding: base64

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)   aGVs

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  bG8g

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)    d29y

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)     bGQ=

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) --sub1--

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) Sub MIME epilogue

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) ")

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - Command: 
URLFETCH ($mail_url2 binary bodypartstructure)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) *** Test 
urlauth-binary command 15/16 (line 85)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - failed: 
Missing 1 untagged replies (1 mismatches)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - first 
unexpanded: URLFETCH $mail_url2sub (BODYPARTSTRUCTURE ("text" "x-myown" 
("charset" "us-ascii") NIL NIL "base64" 11 0 NIL NIL NIL NIL) BINARY {11}

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - first 
expanded: URLFETCH 
imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1.1;urlauth=user+cassandane:internal:00d648274b0fa5a4aec821c7e06757f6055b7d398b 
(BODYPARTSTRUCTURE ("text" "x-myown" ("charset" "us-ascii") NIL NIL 
"base64" 11 0 NIL NIL NIL NIL) BINARY {11}

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary) hello world)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - best 
match: URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1.1;urlauth=user+cassandane:internal:00d648274b0fa5a4aec821c7e06757f6055b7d398b" 
(BODYPARTSTRUCTURE ("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL 
"7BIT" 11 0 NIL NIL NIL NIL)) (BINARY "hello world")

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)  - Command: 
URLFETCH ($mail_url2sub binary bodypartstructure)

=====> Cyrus::ImapTest::run_test[61] (test_urlauth-binary)

============> rawlog.1 <=============
1588762940.837818 I: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE 
AUTH=PLAIN AUTH=LOGIN SASL-IR] 127.0.0.1 Cyrus IMAP 3.2.0-1.el8  server 
ready
1588762940.837854 O: 1.1 LOGIN "cassandane" "testpw"
1588762940.841289 I: 1.1 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 
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 STATUS=SIZE OBJECTID 
SAVEDATE X-CREATEDMODSEQ PREVIEW=FUZZY URLAUTH URLAUTH=BINARY 
LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<10534601A6-1588762940-27748-3-14856087864419154689>
1588762940.841355 O: 1.2 LIST "" "imaptest*"
1588762940.841360 O: 1.3 LSUB "" "imaptest*"
1588762940.842000 I: 1.2 OK Completed (0.000 secs)
1588762940.882025 I: 1.3 OK Completed (0.000 secs)
1588762940.882153 O: 1.4 CREATE "imaptest"
1588762940.890927 I: 1.4 OK [MAILBOXID 
(3cb59094-4bab-4821-82d8-781c3de7122a)] Completed
1588762940.890962 O: 1.5 select imaptest
1588762940.891514 I: * 0 EXISTS
1588762940.891514 I: * 0 RECENT
1588762940.891514 I: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
1588762940.891514 I: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft 
\Deleted \Seen \*)] Ok
1588762940.891514 I: * OK [UIDVALIDITY 1588762941] Ok
1588762940.891514 I: * OK [UIDNEXT 1] Ok
1588762940.891514 I: * OK [HIGHESTMODSEQ 1] Ok
1588762940.891514 I: * OK [URLMECH INTERNAL] Ok
1588762940.891514 I: * OK [ANNOTATIONS 65536] Ok
1588762940.891514 I: 1.5 OK [READ-WRITE] Completed
1588762940.891639 O: 1.6 APPEND "imaptest" "22-Feb-2008 17:06:23 +0100" 
{673+}
1588762940.891661 O: From: user at domain.org
1588762940.891661 O: Date: Sat, 24 Mar 2007 23:00:00 +0200
1588762940.891661 O: Mime-Version: 1.0
1588762940.891661 O: Content-Type: multipart/mixed; boundary="foo
1588762940.891661 O:  bar"
1588762940.891661 O:
1588762940.891661 O: Root MIME prologue
1588762940.891661 O:
1588762940.891661 O: --foo bar
1588762940.891661 O: Content-Type: message/rfc822
1588762940.891661 O:
1588762940.891661 O: From: sub at domain.org
1588762940.891661 O: Date: Sun, 12 Aug 2012 12:34:56 +0300
1588762940.891661 O: Subject: submsg
1588762940.891661 O: Content-Type: multipart/alternative; boundary="sub1"
1588762940.891661 O:
1588762940.891661 O: Sub MIME prologue
1588762940.891661 O: --sub1
1588762940.891661 O: Content-Type: text/x-myown; charset=us-ascii
1588762940.891661 O: Content-Transfer-Encoding: base64
1588762940.891661 O:
1588762940.891661 O: aGVs
1588762940.891661 O: bG8gd29y
1588762940.891661 O: bGQ=
1588762940.891661 O:
1588762940.891661 O: --sub1
1588762940.891661 O: Content-Type: text/x-myown; charset=us-ascii
1588762940.891661 O: Content-Transfer-Encoding: base64
1588762940.891661 O:
1588762940.891661 O:   aGVs
1588762940.891661 O:  bG8g
1588762940.891661 O:    d29y
1588762940.891661 O:     bGQ=
1588762940.891661 O:
1588762940.891661 O:
1588762940.891661 O: --sub1--
1588762940.891661 O: Sub MIME epilogue
1588762940.891661 O:
1588762940.891661 O: --foo bar--
1588762940.891661 O: Root MIME epilogue
1588762940.891696 O:
1588762940.898907 I: * 1 EXISTS
1588762940.898907 I: * 1 RECENT
1588762940.898907 I: 1.6 OK [APPENDUID 1588762941 1] Completed
1588762940.898961 O: 1.7 APPEND "imaptest" "22-Feb-2008 17:06:23 +0100" 
{673+}
1588762940.898969 O: From: user at domain.org
1588762940.898969 O: Date: Sat, 24 Mar 2007 23:00:00 +0200
1588762940.898969 O: Mime-Version: 1.0
1588762940.898969 O: Content-Type: multipart/mixed; boundary="foo
1588762940.898969 O:  bar"
1588762940.898969 O:
1588762940.898969 O: Root MIME prologue
1588762940.898969 O:
1588762940.898969 O: --foo bar
1588762940.898969 O: Content-Type: message/rfc822
1588762940.898969 O:
1588762940.898969 O: From: sub at domain.org
1588762940.898969 O: Date: Sun, 12 Aug 2012 12:34:56 +0300
1588762940.898969 O: Subject: submsg
1588762940.898969 O: Content-Type: multipart/alternative; boundary="sub1"
1588762940.898969 O:
1588762940.898969 O: Sub MIME prologue
1588762940.898969 O: --sub1
1588762940.898969 O: Content-Type: text/x-myown; charset=us-ascii
1588762940.898969 O: Content-Transfer-Encoding: base64
1588762940.898969 O:
1588762940.898969 O: aGVs
1588762940.898969 O: bG8gd29y
1588762940.898969 O: bGQ=
1588762940.898969 O:
1588762940.898969 O: --sub1
1588762940.898969 O: Content-Type: text/x-myown; charset=us-ascii
1588762940.898969 O: Content-Transfer-Encoding: base64
1588762940.898969 O:
1588762940.898969 O:   aGVs
1588762940.898969 O:  bG8g
1588762940.898969 O:    d29y
1588762940.898969 O:     bGQ=
1588762940.898969 O:
1588762940.898969 O:
1588762940.898969 O: --sub1--
1588762940.898969 O: Sub MIME epilogue
1588762940.898969 O:
1588762940.898969 O: --foo bar--
1588762940.898969 O: Root MIME epilogue
1588762940.899002 O:
1588762940.904425 I: * 2 EXISTS
1588762940.904425 I: * 2 RECENT
1588762940.904425 I: 1.7 OK [APPENDUID 1588762941 2] Completed
1588762940.904455 O: 1.8 fetch 1:2 uid
1588762940.904870 I: * 1 FETCH (UID 1)
1588762940.904870 I: * 2 FETCH (UID 2)
1588762940.904870 I: 1.8 OK Completed (0.000 sec)
1588762940.904931 O: 1.9 GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane" 
INTERNAL
1588762940.907456 I: * GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane:internal:0011b22d85d895a3b5ee1cec0839348c1b9c38e90a"
1588762940.907456 I: 1.9 OK Completed
1588762940.907491 O: 1.10 GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane" 
INTERNAL
1588762940.907773 I: * GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane:internal:00d43af988486d6542c34d19b300dbaf742f9748d1"
1588762940.907773 I: 1.10 OK Completed
1588762940.907799 O: 1.11 GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1;urlauth=user+cassandane" 
INTERNAL
1588762940.908078 I: * GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1;urlauth=user+cassandane:internal:005fd11034c1463087bb7c2730d1da10d179955576"
1588762940.908078 I: 1.11 OK Completed
1588762940.908106 O: 1.12 GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1.1;urlauth=user+cassandane" 
INTERNAL
1588762940.908384 I: * GENURLAUTH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1.1;urlauth=user+cassandane:internal:00d648274b0fa5a4aec821c7e06757f6055b7d398b"
1588762940.908384 I: 1.12 OK Completed
1588762940.908407 O: 1.13 URLFETCH 
(imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane:internal:0011b22d85d895a3b5ee1cec0839348c1b9c38e90a 
binary)
1588762940.908912 I: * URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane:internal:0011b22d85d895a3b5ee1cec0839348c1b9c38e90a" 
(BINARY {437}
1588762940.908912 I: From: sub at domain.org
1588762940.908912 I: Date: Sun, 12 Aug 2012 12:34:56 +0300
1588762940.908912 I: Subject: submsg
1588762940.908912 I: Content-Type: multipart/alternative; boundary="sub1"
1588762940.908912 I:
1588762940.908912 I: Sub MIME prologue
1588762940.908912 I: --sub1
1588762940.908912 I: Content-Type: text/x-myown; charset=us-ascii
1588762940.908912 I: Content-Transfer-Encoding: base64
1588762940.908912 I:
1588762940.908912 I: aGVs
1588762940.908912 I: bG8gd29y
1588762940.908912 I: bGQ=
1588762940.908912 I:
1588762940.908912 I: --sub1
1588762940.908912 I: Content-Type: text/x-myown; charset=us-ascii
1588762940.908912 I: Content-Transfer-Encoding: base64
1588762940.908912 I:
1588762940.908912 I:   aGVs
1588762940.908912 I:  bG8g
1588762940.908912 I:    d29y
1588762940.908912 I:     bGQ=
1588762940.908912 I:
1588762940.908912 I:
1588762940.908912 I: --sub1--
1588762940.908912 I: Sub MIME epilogue
1588762940.908912 I: )
1588762940.908912 I: 1.13 OK Completed
1588762940.909032 O: 1.14 URLFETCH 
(imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane:internal:00d43af988486d6542c34d19b300dbaf742f9748d1 
binary)
1588762940.909543 I: * URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane:internal:00d43af988486d6542c34d19b300dbaf742f9748d1" 
(BINARY {11}
1588762940.909543 I: hello world)
1588762940.909543 I: 1.14 OK Completed
1588762940.909574 O: 1.15 URLFETCH 
(imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane:internal:0011b22d85d895a3b5ee1cec0839348c1b9c38e90a 
bodypartstructure)
1588762940.910061 I: * URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1;urlauth=user+cassandane:internal:0011b22d85d895a3b5ee1cec0839348c1b9c38e90a" 
(BODYPARTSTRUCTURE ("MESSAGE" "RFC822" NIL NIL NIL "7BIT" 437 ("Sun, 12 
Aug 2012 12:34:56 +0300" "submsg" ((NIL NIL "sub" "domain.org")) ((NIL 
NIL "sub" "domain.org")) ((NIL NIL "sub" "domain.org")) NIL NIL NIL NIL 
NIL) (("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL "BASE64" 22 3 NIL 
NIL NIL NIL)("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL "BASE64" 47 
5 NIL NIL NIL NIL) "ALTERNATIVE" ("BOUNDARY" "sub1") NIL NIL NIL) 26 NIL 
NIL NIL NIL))
1588762940.910061 I: 1.15 OK Completed
1588762940.910135 O: 1.16 URLFETCH 
(imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane:internal:00d43af988486d6542c34d19b300dbaf742f9748d1 
bodypartstructure)
1588762940.910637 I: * URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane:internal:00d43af988486d6542c34d19b300dbaf742f9748d1" 
(BODYPARTSTRUCTURE ("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL 
"BASE64" 22 3 NIL NIL NIL NIL))
1588762940.910637 I: 1.16 OK Completed
1588762940.910670 O: 1.17 URLFETCH 
(imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1;urlauth=user+cassandane:internal:005fd11034c1463087bb7c2730d1da10d179955576 
binary bodypartstructure)
1588762940.911157 I: * URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1;urlauth=user+cassandane:internal:005fd11034c1463087bb7c2730d1da10d179955576" 
(BODYPARTSTRUCTURE ("MESSAGE" "RFC822" NIL NIL NIL "7BIT" 437 ("Sun, 12 
Aug 2012 12:34:56 +0300" "submsg" ((NIL NIL "sub" "domain.org")) ((NIL 
NIL "sub" "domain.org")) ((NIL NIL "sub" "domain.org")) NIL NIL NIL NIL 
NIL) (("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL "BASE64" 22 3 NIL 
NIL NIL NIL)("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL "BASE64" 47 
5 NIL NIL NIL NIL) "ALTERNATIVE" ("BOUNDARY" "sub1") NIL NIL NIL) 26 NIL 
NIL NIL NIL)) (BINARY {437}
1588762940.911157 I: From: sub at domain.org
1588762940.911157 I: Date: Sun, 12 Aug 2012 12:34:56 +0300
1588762940.911157 I: Subject: submsg
1588762940.911157 I: Content-Type: multipart/alternative; boundary="sub1"
1588762940.911157 I:
1588762940.911157 I: Sub MIME prologue
1588762940.911157 I: --sub1
1588762940.911157 I: Content-Type: text/x-myown; charset=us-ascii
1588762940.911157 I: Content-Transfer-Encoding: base64
1588762940.911157 I:
1588762940.911157 I: aGVs
1588762940.911157 I: bG8gd29y
1588762940.911157 I: bGQ=
1588762940.911157 I:
1588762940.911157 I: --sub1
1588762940.911157 I: Content-Type: text/x-myown; charset=us-ascii
1588762940.911157 I: Content-Transfer-Encoding: base64
1588762940.911157 I:
1588762940.911157 I:   aGVs
1588762940.911157 I:  bG8g
1588762940.911157 I:    d29y
1588762940.911157 I:     bGQ=
1588762940.911157 I:
1588762940.911157 I:
1588762940.911157 I: --sub1--
1588762940.911157 I: Sub MIME epilogue
1588762940.911157 I: )
1588762940.911157 I: 1.17 OK Completed
1588762940.911359 O: 1.18 URLFETCH 
(imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane:internal:00d43af988486d6542c34d19b300dbaf742f9748d1 
binary)
1588762940.911869 I: * URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=1/;section=1.1;urlauth=user+cassandane:internal:00d43af988486d6542c34d19b300dbaf742f9748d1" 
(BINARY {11}
1588762940.911869 I: hello world)
1588762940.911869 I: 1.18 OK Completed
1588762940.911916 O: 1.19 URLFETCH 
(imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1.1;urlauth=user+cassandane:internal:00d648274b0fa5a4aec821c7e06757f6055b7d398b 
binary bodypartstructure)
1588762940.912421 I: * URLFETCH 
"imap://cassandane@127.0.0.1/imaptest/;uid=2/;section=1.1;urlauth=user+cassandane:internal:00d648274b0fa5a4aec821c7e06757f6055b7d398b" 
(BODYPARTSTRUCTURE ("TEXT" "X-MYOWN" ("CHARSET" "us-ascii") NIL NIL 
"7BIT" 11 0 NIL NIL NIL NIL)) (BINARY {11}
1588762940.912421 I: hello world)
1588762940.912421 I: 1.19 OK Completed
1588762940.912482 O: 1.20 logout
1588762940.912760 I: * BYE LOGOUT received
1588762940.912760 I: 1.20 OK Completed
=====> Cyrus::TestCase::tear_down[98] (test_urlauth-binary) Beginning 
tear_down
=====> Instance::stop[773] stop main instance for test 
test_urlauth-binary: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601A6
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 27740
=====> Util::Wait::timed_wait[1376] Waited 0.010115 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 27719
2020/05/06-13:02:20 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 27737
=====> Instance::__ANON__[1459] killing smtpd 27719
=====> Cyrus::TestCase::tear_down[98] ---------- END test_urlauth-binary 
----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19104 19105

8) Master.service_dup_port
  expected 1, got 0 at Cassandane/Cyrus/Master.pm line 677.
 
Cassandane::Cyrus::Master::test_service_dup_port(Cassandane::Cyrus::Master=HASH(0x5613687b59b0)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 75
         [...framework calls elided...]

Annotations:
=====> Cyrus::TestCase::set_up[72] ---------- BEGIN 
test_service_dup_port ----------
=====> Cyrus::TestCase::set_up[72] (test_service_dup_port) Calling test 
function
=====> Cyrus::Master::test_service_dup_port[75] (test_service_dup_port) 
successful two services with listen=
=====> Cyrus::Master::test_service_dup_port[75] (test_service_dup_port) 
parameters which reference the same IPv4 port
=====> Instance::start[230] start unknown: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF
2020/05/06-13:03:31 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(29333)
Resolved [localhost]:19126 to [::1]:19126, IPv6
Resolved [localhost]:19126 to [127.0.0.1]:19126, IPv4
Binding to TCP port 19126 on host ::1 with IPv6
Binding to TCP port 19126 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 29333
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF as 29344
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF/conf/master.log"
=====> Instance::_fork_command[1562] child pid=29347
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service B is 
listening on 127.0.0.1:19125
=====> Util::Wait::timed_wait[909] Waited 0.096851 sec for 
127.0.0.1:19125 to be in LISTEN state
=====> GenericDaemon::_is_listening_af[375] is_listening: service A is 
listening on 127.0.0.1:19125
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::start[230] started unknown: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::tear_down[81] (test_service_dup_port) Beginning 
tear_down
=====> Instance::stop[773] stop unknown: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602AF
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 29349
=====> Util::Wait::timed_wait[1376] Waited 0.010117 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 29333
2020/05/06-13:03:32 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 29344
=====> Instance::__ANON__[1459] killing smtpd 29333
=====> Cyrus::TestCase::tear_down[81] ---------- END 
test_service_dup_port ----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19125 19126

14) Rename.intermediate_cleanup
  EXPECTED TO SEE $VAR1 = {
   'user.cassandane.INBOX.a' => undef,
   'user.cassandane.a' => undef,
   'user.cassandane.a.b' => undef,
   'user.cassandane.a.b.c' => undef,
   'user.cassandane.x' => undef,
   'user.cassandane.x.y' => undef,
   'user.cassandane.x.y.z' => undef,
};
$VAR2 = [];
  at Cassandane/Cyrus/Rename.pm line 699.
 
Cassandane::Cyrus::Rename::_match_intermediates(Cassandane::Cyrus::Rename=HASH(0x561368e009e8), 
"user.cassandane.a", undef, "user.cassandane.a.b", undef, 
"user.cassandane.a.b.c", undef, "user.cassandane.x", ...) called at 
Cassandane/Cyrus/Rename.pm line 728
 
Cassandane::Cyrus::Rename::test_intermediate_cleanup(Cassandane::Cyrus::Rename=HASH(0x561368e009e8)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 75
         [...framework calls elided...]

Annotations:
=====> Cyrus::TestCase::set_up[67] ---------- BEGIN 
test_intermediate_cleanup ----------
=====> Instance::start[659] start main instance for test 
test_intermediate_cleanup: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103
2020/05/06-13:07:05 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(722)
Resolved [localhost]:19109 to [::1]:19109, IPv6
Resolved [localhost]:19109 to [127.0.0.1]:19109, IPv4
Binding to TCP port 19109 on host ::1 with IPv6
Binding to TCP port 19109 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 722
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103 as 729
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103/conf/master.log"
=====> Instance::_fork_command[1562] child pid=731
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19110
=====> Util::Wait::timed_wait[909] Waited 0.160887 sec for 
127.0.0.1:19110 to be in LISTEN state
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::create_user[1175] create user cassandane
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19110
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<10534601103-1588763226-751-1-13228619984216888929>
C: 3 create user.cassandane
S: 3 OK [MAILBOXID (9a1a3ee5-0445-4062-9643-b384bd07fac5)] 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=57
=====> Instance::start[659] started main instance for test 
test_intermediate_cleanup: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::set_up[67] (test_intermediate_cleanup) Calling 
test function
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19110
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED COMPRESS=DEFLATE 
X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE 
X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<10534601103-1588763226-751-2-11566141531137890733>
C: 3 create INBOX.a.b.c.subdir
S: 3 OK [MAILBOXID (2c925091-d80f-4eae-b8e4-a5dbe3f6a3ae)] Completed
C: 4 create INBOX.x.y.z.subdir
S: 4 OK [MAILBOXID (24e1cbe2-7cbc-4ca1-9275-28909234974d)] Completed
C: 5 create INBOX.INBOX.subinbox
S: 5 OK [MAILBOXID (5a05787f-a376-4111-940d-621e740a33fb)] Completed
C: 6 create INBOX.INBOX.a.b
S: 6 OK [MAILBOXID (db186291-f886-4a0f-8fa3-c46bc3d2686c)] Completed
=====> Cyrus::TestCase::tear_down[73] (test_intermediate_cleanup) 
Beginning tear_down
C: 7 logout
S: * BYE LOGOUT received
S: 7 OK Completed
A: Release socket, fileno=57
=====> Instance::stop[773] stop main instance for test 
test_intermediate_cleanup: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601103
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 732
=====> Util::Wait::timed_wait[1376] Waited 0.026361 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 722
2020/05/06-13:07:07 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 729
=====> Instance::__ANON__[1459] killing smtpd 722
=====> Cyrus::TestCase::tear_down[73] ---------- END 
test_intermediate_cleanup ----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19109 19110

16) Replication.splitbrain_mailbox
  Boolean assertion failed at 
/usr/share/perl5/vendor_perl/Test/Unit/Exception.pm line 13.
 
Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x561369cfee08), 
"-package", "Cassandane::Cyrus::Replication", "-file", 
"Cassandane/Cyrus/Replication.pm", "-line", 195, "-object", ...) called 
at /usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 85
 
Test::Unit::Assert::do_assertion(Cassandane::Cyrus::Replication=HASH(0x561368ef8448), 
Test::Unit::Assertion::Boolean=SCALAR(0x561369f434a8), 
"Cassandane::Cyrus::Replication", "Cassandane/Cyrus/Replication.pm", 
195) called at /usr/share/perl5/vendor_perl/Test/Unit/Assert.pm line 19
 
Test::Unit::Assert::assert(Cassandane::Cyrus::Replication=HASH(0x561368ef8448)) 
called at Cassandane/Cyrus/Replication.pm line 195
 
Cassandane::Cyrus::Replication::test_splitbrain_mailbox(Cassandane::Cyrus::Replication=HASH(0x561368ef8448)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 75
         [...framework calls elided...]

Annotations:
=====> Cyrus::TestCase::set_up[61] ---------- BEGIN 
test_splitbrain_mailbox ----------
=====> Instance::start[659] start main instance for test 
test_splitbrain_mailbox: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B
2020/05/06-13:08:39 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(2354)
Resolved [localhost]:19107 to [::1]:19107, IPv6
Resolved [localhost]:19107 to [127.0.0.1]:19107, IPv4
Binding to TCP port 19107 on host ::1 with IPv6
Binding to TCP port 19107 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 2354
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B as 2364
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/conf/master.log"
=====> Instance::_fork_command[1562] child pid=2366
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19108
=====> Util::Wait::timed_wait[909] Waited 0.162691 sec for 
127.0.0.1:19108 to be in LISTEN state
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::create_user[1175] create user cassandane
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19108
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460111B-1588763320-2377-1-3530593186186262734>
C: 3 create user.cassandane
S: 3 OK [MAILBOXID (b974b2f5-e232-482f-87d5-83cc4eab3616)] 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=57
=====> Instance::start[659] started main instance for test 
test_splitbrain_mailbox: cyrus version 3.2.0-1.el8
=====> Instance::start[663] start replica instance for test 
test_splitbrain_mailbox: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C
2020/05/06-13:08:40 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(2378)
Resolved [localhost]:19109 to [::1]:19109, IPv6
Resolved [localhost]:19109 to [127.0.0.1]:19109, IPv4
Binding to TCP port 19109 on host ::1 with IPv6
Binding to TCP port 19109 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 2378
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C as 2394
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C/conf/master.log"
=====> Instance::_fork_command[1562] child pid=2397
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19110
=====> Util::Wait::timed_wait[909] Waited 0.165849 sec for 
127.0.0.1:19110 to be in LISTEN state
=====> GenericDaemon::_is_listening_af[375] is_listening: service sync 
is listening on 127.0.0.1:19106
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::start[663] started replica instance for test 
test_splitbrain_mailbox: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::run_replication[684] (test_splitbrain_mailbox) 
running replication
=====> Instance::_find_binary[525] Found binary sync_client in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin/sync_client" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/conf/imapd.conf" 
"-v" "-v" "-o" "-S" "127.0.0.1" "-u" "cassandane"
=====> Instance::_fork_command[1562] child pid=2413
=====> Instance::_fork_command[1562] setting core size limit to 104857600
1053460111B/sync_client[2413]: SQL backend defaulting to engine 'mysql'
1053460111B/sync_client[2413]: imap_sasl_parsesuccess(): input is: A01 
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] Success (no 
protection) SESSIONID=<1053460111C-1588763322-2415-1-1324532802764138914>
1053460111B/sync_client[2413]: imap_sasl_parsesuccess(): found 
capability string: [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 
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 STATUS=SIZE OBJECTID 
SAVEDATE X-CREATEDMODSEQ PREVIEW=FUZZY URLAUTH URLAUTH=BINARY 
LOGINDISABLED UNAUTHENTICATE COMPRESS=DEFLATE X-QUOTA=STORAGE 
X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE]
USER cassandane
 >1588763322>S0 SYNCGET USER cassandane
<1588763322<S0 OK success
MAILBOX user.cassandane
 >1588763322>S1 SYNCAPPLY MAILBOX %(UNIQUEID 
b974b2f5-e232-482f-87d5-83cc4eab3616 MBOXNAME user.cassandane SYNC_CRC 0 
SYNC_CRC_ANNOT 12345678 LAST_UID 0 HIGHESTMODSEQ 4 RECENTUID 0 
RECENTTIME 0 LAST_APPENDDATE 0 POP3_LAST_LOGIN 0 POP3_SHOW_AFTER 0 
UIDVALIDITY 1588763321 PARTITION default ACL "cassandane 
lrswipkxtecdan       admin   lrswipkxtecdan  anyone  p       " OPTIONS P 
CREATEDMODSEQ 1 FOLDERMODSEQ 4 RECORD ())
<1588763322<S1 OK success
 >1588763322>Q01 LOGOUT
<1588763322<* BYE LOGOUT received
Q01 OK Completed
=====> Cyrus::TestCase::set_up[61] (test_splitbrain_mailbox) Calling 
test function
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19108
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED COMPRESS=DEFLATE 
X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE 
X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460111B-1588763322-2377-1-14193159480434873286>
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19110
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED COMPRESS=DEFLATE 
X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE 
X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460111C-1588763322-2424-1-14961550007535884969>
C: 3 create INBOX.src-name
S: 3 OK [MAILBOXID (5f9e1a73-0dd3-4969-a0d0-42a56c8b162d)] Completed
=====> Cyrus::Replication::test_splitbrain_mailbox[75] 
(test_splitbrain_mailbox) run initial replication
=====> Cyrus::TestCase::run_replication[180] (test_splitbrain_mailbox) 
running replication
C: 4 logout
S: * BYE LOGOUT received
S: 4 OK Completed
A: Release socket, fileno=58
C: 3 logout
S: * BYE LOGOUT received
S: 3 OK Completed
A: Release socket, fileno=59
=====> Instance::_find_binary[525] Found binary sync_client in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin/sync_client" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/conf/imapd.conf" 
"-v" "-v" "-o" "-S" "127.0.0.1" "-u" "cassandane"
=====> Instance::_fork_command[1562] child pid=2427
=====> Instance::_fork_command[1562] setting core size limit to 104857600
1053460111B/sync_client[2427]: SQL backend defaulting to engine 'mysql'
1053460111B/sync_client[2427]: imap_sasl_parsesuccess(): input is: A01 
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] Success (no 
protection) SESSIONID=<1053460111C-1588763322-2415-2-1484725736988109801>
1053460111B/sync_client[2427]: imap_sasl_parsesuccess(): found 
capability string: [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 
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 STATUS=SIZE OBJECTID 
SAVEDATE X-CREATEDMODSEQ PREVIEW=FUZZY URLAUTH URLAUTH=BINARY 
LOGINDISABLED UNAUTHENTICATE COMPRESS=DEFLATE X-QUOTA=STORAGE 
X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE]
USER cassandane
 >1588763322>S0 SYNCGET USER cassandane
<1588763322<* MAILBOX %(UNIQUEID b974b2f5-e232-482f-87d5-83cc4eab3616 
MBOXNAME user.cassandane SYNC_CRC 0 SYNC_CRC_ANNOT 12345678 LAST_UID 0 
HIGHESTMODSEQ 4 RECENTUID 0 RECENTTIME 0 LAST_APPENDDATE 0 
POP3_LAST_LOGIN 0 POP3_SHOW_AFTER 0 UIDVALIDITY 1588763321 PARTITION 
default ACL "cassandane lrswipkxtecdan  adminlrswipkxtecdan  anyone  p 
     " OPTIONS P CREATEDMODSEQ 1 FOLDERMODSEQ 4)
S0 OK success
MAILBOX user.cassandane.src-name
 >1588763322>S1 SYNCAPPLY MAILBOX %(UNIQUEID 
5f9e1a73-0dd3-4969-a0d0-42a56c8b162d MBOXNAME user.cassandane.src-name 
SYNC_CRC 0 SYNC_CRC_ANNOT 12345678 LAST_UID 0 HIGHESTMODSEQ 1 RECENTUID 
0 RECENTTIME 0 LAST_APPENDDATE 0 POP3_LAST_LOGIN 0 POP3_SHOW_AFTER 0 
UIDVALIDITY 1588763323 PARTITION default ACL "cassandane lrswipkxtecdan 
  admin   lrswipkxtecdan  anyone  p       " OPTIONS P CREATEDMODSEQ 1 
FOLDERMODSEQ 1 RECORD ())
<1588763322<S1 OK success
 >1588763322>Q01 LOGOUT
<1588763322<* BYE LOGOUT received
Q01 OK Completed
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19108
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED COMPRESS=DEFLATE 
X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE 
X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460111B-1588763322-2377-2-7264655289928192886>
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 1588763321] Ok
S: * OK [UIDNEXT 1] Ok
S: * OK [HIGHESTMODSEQ 4] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 3 OK [READ-WRITE] Completed
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19110
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED COMPRESS=DEFLATE 
X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE 
X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460111C-1588763322-2424-2-3312503163462846826>
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 1588763321] Ok
S: * OK [UIDNEXT 1] Ok
S: * OK [HIGHESTMODSEQ 4] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 3 OK [READ-WRITE] Completed
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19108
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED COMPRESS=DEFLATE 
X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE 
X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460111B-1588763322-2432-1-15452859474456518124>
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19110
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY AUTH=PLAIN AUTH=LOGIN SASL-IR 
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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED COMPRESS=DEFLATE 
X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE 
X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<1053460111C-1588763322-2433-1-1415586701204451406>
C: 3 list "INBOX.*" "*"
S: * LIST (\HasNoChildren) "." INBOX.src-name
S: 3 OK Completed (0.000 secs 1 calls)
C: 3 list "INBOX.*" "*"
S: * LIST (\HasNoChildren) "." INBOX.src-name
S: 3 OK Completed (0.000 secs 1 calls)
C: 4 lsub "*" "*"
S: 4 OK Completed (0.000 secs)
C: 4 lsub "*" "*"
S: 4 OK Completed (0.000 secs)
C: 5 getquotaroot INBOX
S: * QUOTAROOT INBOX
S: 5 OK Completed
C: 5 getquotaroot INBOX
S: * QUOTAROOT INBOX
S: 5 OK Completed
C: 6 status INBOX (messages uidnext unseen recent uidvalidity highestmodseq)
S: * STATUS INBOX (MESSAGES 0 RECENT 0 UIDNEXT 1 UIDVALIDITY 1588763321 
UNSEEN 0 HIGHESTMODSEQ 4)
S: 6 OK Completed
C: 6 status INBOX (messages uidnext unseen recent uidvalidity highestmodseq)
S: * STATUS INBOX (MESSAGES 0 RECENT 0 UIDNEXT 1 UIDVALIDITY 1588763321 
UNSEEN 0 HIGHESTMODSEQ 4)
S: 6 OK Completed
C: 7 status INBOX.src-name (messages uidnext unseen recent uidvalidity 
highestmodseq)
S: * STATUS INBOX.src-name (MESSAGES 0 RECENT 0 UIDNEXT 1 UIDVALIDITY 
1588763323 UNSEEN 0 HIGHESTMODSEQ 1)
S: 7 OK Completed
C: 7 status INBOX.src-name (messages uidnext unseen recent uidvalidity 
highestmodseq)
S: * STATUS INBOX.src-name (MESSAGES 0 RECENT 0 UIDNEXT 1 UIDVALIDITY 
1588763323 UNSEEN 0 HIGHESTMODSEQ 1)
S: 7 OK Completed
A: is_open test
A: is_open test received timeout, still open
C: 8 logout
S: * BYE LOGOUT received
S: 8 OK Completed
A: Release socket, fileno=61
A: is_open test
A: is_open test received timeout, still open
C: 8 logout
S: * BYE LOGOUT received
S: 8 OK Completed
A: Release socket, fileno=60
C: 4 rename INBOX.src-name INBOX.dest-name
S: * OK rename INBOX.src-name INBOX.dest-name
S: 4 OK Completed
=====> Cyrus::Replication::test_splitbrain_mailbox[75] 
(test_splitbrain_mailbox) try replicating just the mailbox by name fails 
due to duplicate uniqueid
=====> Cyrus::TestCase::run_replication[190] (test_splitbrain_mailbox) 
running replication
C: 5 logout
S: * BYE LOGOUT received
S: 5 OK Completed
A: Release socket, fileno=58
C: 4 logout
S: * BYE LOGOUT received
S: 4 OK Completed
A: Release socket, fileno=59
=====> Instance::_find_binary[525] Found binary sync_client in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin/sync_client" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B/conf/imapd.conf" 
"-v" "-v" "-o" "-S" "127.0.0.1" "-m" "user.cassandane.dest-name"
=====> Instance::_fork_command[1562] child pid=2434
=====> Instance::_fork_command[1562] setting core size limit to 104857600
1053460111B/sync_client[2434]: SQL backend defaulting to engine 'mysql'
1053460111B/sync_client[2434]: imap_sasl_parsesuccess(): input is: A01 
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] Success (no 
protection) SESSIONID=<1053460111C-1588763323-2415-1-8172331016602020637>
1053460111B/sync_client[2434]: imap_sasl_parsesuccess(): found 
capability string: [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 
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 STATUS=SIZE OBJECTID 
SAVEDATE X-CREATEDMODSEQ PREVIEW=FUZZY URLAUTH URLAUTH=BINARY 
LOGINDISABLED UNAUTHENTICATE COMPRESS=DEFLATE X-QUOTA=STORAGE 
X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE]
MAILBOXES user.cassandane.dest-name
 >1588763323>S0 SYNCGET MAILBOXES (user.cassandane.dest-name)
<1588763323<S0 OK success
MAILBOX user.cassandane.dest-name
 >1588763323>S1 SYNCAPPLY MAILBOX %(UNIQUEID 
5f9e1a73-0dd3-4969-a0d0-42a56c8b162d MBOXNAME user.cassandane.dest-name 
SYNC_CRC 0 SYNC_CRC_ANNOT 12345678 LAST_UID 0 HIGHESTMODSEQ 2 RECENTUID 
0 RECENTTIME 0 LAST_APPENDDATE 0 POP3_LAST_LOGIN 0 POP3_SHOW_AFTER 0 
UIDVALIDITY 1588763323 PARTITION default ACL "cassandanelrswipkxtecdan 
admin   lrswipkxtecdan  anyone  p       " OPTIONS P CREATEDMODSEQ 1 
FOLDERMODSEQ 2 RECORD ())
<1588763323<S1 NO IMAP_MAILBOX_MOVED Mailbox exists with another name or 
uniqueid
1053460111B/sync_client[2434]: MAILBOX received NO response: 
IMAP_MAILBOX_MOVED Mailbox exists with another name or uniqueid
1053460111B/sync_client[2434]: do_folders(): update failed: 
user.cassandane.dest-name 'Mailbox has been moved to another server'
Error from sync_do_mailboxes(): bailing out!
1053460111B/sync_client[2434]: Error in sync_do_mailboxes(): bailing out!
 >1588763323>Q01 LOGOUT
<1588763323<* BYE LOGOUT received
Q01 OK Completed
=====> Cyrus::TestCase::tear_down[67] (test_splitbrain_mailbox) 
Beginning tear_down
=====> Instance::stop[773] stop main instance for test 
test_splitbrain_mailbox: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111B
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 2367
=====> Util::Wait::timed_wait[1376] Waited 0.029108 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 2354
2020/05/06-13:08:43 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 2364
=====> Instance::__ANON__[1459] killing smtpd 2354
=====> Instance::stop[791] stop replica instance for test 
test_splitbrain_mailbox: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/1053460111C
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 2398
=====> Util::Wait::timed_wait[1376] Waited 0.033878 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 2378
2020/05/06-13:08:43 Server closing!
=====> Instance::__ANON__[1459] killing smtpd 2354
=====> Instance::__ANON__[1459] killing notifyd 2364
=====> Instance::__ANON__[1459] killing smtpd 2354
=====> Instance::__ANON__[1459] killing notifyd 2364
=====> Instance::__ANON__[1459] killing smtpd 2354
=====> Instance::__ANON__[1459] killing notifyd 2364
=====> Instance::__ANON__[1459] killing smtpd 2354
=====> Instance::__ANON__[1459] killing notifyd 2364
=====> Instance::__ANON__[1420] killing notifyd 2394
=====> Instance::__ANON__[1459] killing smtpd 2378
=====> Instance::__ANON__[1459] killing smtpd 2354
=====> Instance::__ANON__[1459] killing notifyd 2364
=====> Cyrus::TestCase::tear_down[67] ---------- END 
test_splitbrain_mailbox ----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19106 19107 19108 19109 19110

19) SearchFuzzy.striphtml_alternative
  Structures begin differing at:
   $a->[0] = Does not exist
   $b->[0] = '1'
  at Cassandane/Cyrus/SearchFuzzy.pm line 1405.
 
Cassandane::Cyrus::SearchFuzzy::test_striphtml_alternative(Cassandane::Cyrus::SearchFuzzy=HASH(0x56136902bbd8)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 75
         [...framework calls elided...]

Annotations:
=====> Cyrus::TestCase::set_up[62] ---------- BEGIN 
test_striphtml_alternative ----------
=====> Instance::start[659] start main instance for test 
test_striphtml_alternative: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129
2020/05/06-13:09:19 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(3068)
Resolved [localhost]:19117 to [::1]:19117, IPv6
Resolved [localhost]:19117 to [127.0.0.1]:19117, IPv4
Binding to TCP port 19117 on host ::1 with IPv6
Binding to TCP port 19117 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 3068
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129 as 3083
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129/conf/master.log"
=====> Instance::_fork_command[1562] child pid=3086
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19118
=====> Util::Wait::timed_wait[909] Waited 0.155084 sec for 
127.0.0.1:19118 to be in LISTEN state
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::create_user[1175] create user cassandane
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19118
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY 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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<10534601129-1588763360-3101-1-12939915791064375203>
C: 3 create user.cassandane
S: 3 OK [MAILBOXID (7f91fb23-af8b-427d-b58b-6ae1af4f3c75)] 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=57
=====> Instance::start[659] started main instance for test 
test_striphtml_alternative: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::set_up[62] (test_striphtml_alternative) Calling 
test function
=====> Cyrus::SearchFuzzy::set_up[58] (test_striphtml_alternative) 
Xapian CJK tokeniser 'ngrams' detected.

=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19118
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY 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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY 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=<10534601129-1588763360-3101-2-1219524062886537765>
=====> Cyrus::SearchFuzzy::test_striphtml_alternative[75] Index message 
with both html and plain text part
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 1588763361] Ok
S: * OK [UIDNEXT 1] Ok
S: * OK [HIGHESTMODSEQ 4] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 3 OK [READ-WRITE] Completed
C: 4 append inbox " 6-May-2020 13:09:20 +0200" {896}
S: + go ahead
C: Return-Path: <agn at hotmail.com>
Received: from gateway (gateway.vmtom.com [10.0.0.1])
         by ahost (ahost.vmtom.com[10.0.0.2]); Wed, 06 May 2020 13:09:20 
+0200
Received: from mail.hotmail.com (mail.hotmail.com [192.168.0.1])
         by gateway.vmtom.com (gateway.vmtom.com [10.0.0.1]); Wed, 06 
May 2020 13:09:20 +0200
Mime-Version: 1.0
Content-Type: multipart/alternative; boundary="boundary_1"
Content-Transfer-Encoding: 7bit
Subject: test
From: Abigail G. Nguyen <agn at hotmail.com>
Message-ID: <fake.1588763360.36141 at hotmail.com>
Date: Wed, 06 May 2020 13:09:20 +0200
To: Test User <test at vmtom.com>
X-Cassandane-Unique: 4e21b7930641479e6b0f5e3f5e557be3ef57609b


--boundary_1
Content-Type: text/plain; charset="UTF-8"

<div>This is a plain text body with <b>html</b>.</div>

--boundary_1
Content-Type: text/html; charset="UTF-8"

<div>This is an html body.</div>

--boundary_1--
C:
S: * 1 EXISTS
S: * 1 RECENT
S: 4 OK [APPENDUID 1588763361 1] Completed
=====> Instance::_find_binary[525] Found binary squatter in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin/squatter" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129/conf/imapd.conf"
=====> Instance::_fork_command[1562] child pid=3102
=====> Instance::_fork_command[1562] setting core size limit to 104857600
10534601129/squatter[3102]: SQL backend defaulting to engine 'mysql'
10534601129/squatter[3102]: extractor_init((nil))
10534601129/squatter[3102]: indexing mailboxes
10534601129/squatter[3102]: indexing mailbox user.cassandane...
10534601129/squatter[3102]: Xapian committed 1 updates in 0.003525 sec
10534601129/squatter[3102]: done indexing mailboxes
10534601129/squatter[3102]: extractor_destroy(0x55e04b412ba0)
=====> Cyrus::SearchFuzzy::test_striphtml_alternative[75] Assert that 
HTML in plain text is stripped
C: 5 search fuzzy body html
S: * SEARCH 1
S: 5 OK Completed (1 msgs in 0.002 secs)
C: 6 search fuzzy body div
S: * SEARCH 1
S: 6 OK Completed (1 msgs in 0.001 secs)
=====> Cyrus::TestCase::tear_down[93] (test_striphtml_alternative) 
Beginning tear_down
C: 7 logout
S: * BYE LOGOUT received
S: 7 OK Completed
A: Release socket, fileno=57
=====> Instance::stop[773] stop main instance for test 
test_striphtml_alternative: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534601129
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 3088
=====> Util::Wait::timed_wait[1376] Waited 0.013027 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 3068
2020/05/06-13:09:20 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 3083
=====> Instance::__ANON__[1459] killing smtpd 3068
=====> Cyrus::TestCase::tear_down[93] ---------- END 
test_striphtml_alternative ----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19117 19118

20) SearchFuzzy.striphtml_rfc822
  Structures begin differing at:
   $a->[0] = Does not exist
   $b->[0] = '1'
  at Cassandane/Cyrus/SearchFuzzy.pm line 1472.
 
Cassandane::Cyrus::SearchFuzzy::test_striphtml_rfc822(Cassandane::Cyrus::SearchFuzzy=HASH(0x561368f186a0)) 
called at /usr/share/perl5/vendor_perl/Test/Unit/TestCase.pm line 75
         [...framework calls elided...]

Annotations:
=====> Cyrus::TestCase::set_up[62] ---------- BEGIN 
test_striphtml_rfc822 ----------
=====> Instance::start[659] start main instance for test 
test_striphtml_rfc822: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129
2020/05/06-13:09:21 Cassandane::Net::SMTPServer (type 
Net::Server::PreForkSimple) starting! pid(3116)
Resolved [localhost]:19122 to [::1]:19122, IPv6
Resolved [localhost]:19122 to [127.0.0.1]:19122, IPv4
Binding to TCP port 19122 on host ::1 with IPv6
Binding to TCP port 19122 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '12 0'
User Not Defined.  Defaulting to EUID '76'
=====> Instance::_start_smtpd[1119] started smtpd as 3116
=====> Instance::_find_binary[525] Found binary ctl_cyrusdb in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_find_binary[525] Found binary imapd in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_start_notifyd[1151] started notifyd for 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129 as 3135
=====> Instance::_start_master[1153] _start_master: logging to 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129/conf/master.log
=====> Instance::_find_binary[525] Found binary master in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/libexec/cyrus-imapd/master" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129/conf/imapd.conf" 
"-l" "255" "-p" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129/run/master.pid" 
"-d" "-M" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129/conf/cyrus.conf" 
"-L" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129/conf/master.log"
=====> Instance::_fork_command[1562] child pid=3137
=====> Instance::_fork_command[1562] setting core size limit to 104857600
=====> Instance::_start_master[1153] _start_master: waiting for PID file
=====> Instance::_start_master[1153] _start_master: PID file present and 
correct
=====> Instance::_start_master[1153] _start_master: PID waiting for services
=====> GenericDaemon::_is_listening_af[375] is_listening: service imap 
is listening on 127.0.0.1:19123
=====> Util::Wait::timed_wait[909] Waited 0.187334 sec for 
127.0.0.1:19123 to be in LISTEN state
=====> Instance::_start_master[1153] _start_master: all services listening
=====> Instance::create_user[1175] create user cassandane
=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19123
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY 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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY URLAUTH URLAUTH=BINARY LOGINDISABLED UNAUTHENTICATE 
XCONVERSATIONS COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE 
X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in 
SESSIONID=<10534602129-1588763362-3153-1-15480066184726821442>
C: 3 create user.cassandane
S: 3 OK [MAILBOXID (9a24ad53-daf0-481e-b4cd-c6ef64fcd3d4)] 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=57
=====> Instance::start[659] started main instance for test 
test_striphtml_rfc822: cyrus version 3.2.0-1.el8
=====> Cyrus::TestCase::set_up[62] (test_striphtml_rfc822) Calling test 
function
=====> Cyrus::SearchFuzzy::set_up[58] (test_striphtml_rfc822) Xapian CJK 
tokeniser 'ngrams' detected.

=====> Util::Socket::create_client_socket[94] create_client_socket INET 
host=127.0.0.1 port=19123
C: 1 capability
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE AUTH=PLAIN AUTH=LOGIN 
SASL-IR] imap.example.com Cyrus IMAP 3.2.0-1.el8  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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY 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"
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 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 STATUS=SIZE OBJECTID SAVEDATE X-CREATEDMODSEQ 
PREVIEW=FUZZY 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=<10534602129-1588763362-3153-2-17017686861392155066>
=====> Cyrus::SearchFuzzy::test_striphtml_rfc822[75] Index message with 
attached rfc822 message
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 1588763363] Ok
S: * OK [UIDNEXT 1] Ok
S: * OK [HIGHESTMODSEQ 4] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * OK [ANNOTATIONS 65536] Ok
S: 3 OK [READ-WRITE] Completed
C: 4 append inbox " 6-May-2020 13:09:22 +0200" {1184}
S: + go ahead
C: Return-Path: <Isabella.Williams at yahoo.com>
Received: from gateway (gateway.vmtom.com [10.0.0.1])
         by ahost (ahost.vmtom.com[10.0.0.2]); Wed, 06 May 2020 13:09:22 
+0200
Received: from mail.yahoo.com (mail.yahoo.com [192.168.0.1])
         by gateway.vmtom.com (gateway.vmtom.com [10.0.0.1]); Wed, 06 
May 2020 13:09:22 +0200
Mime-Version: 1.0
Content-Type: multipart/mixed; boundary="boundary_1"
Content-Transfer-Encoding: 7bit
Subject: test
From: Isabella E. Williams <Isabella.Williams at yahoo.com>
Message-ID: <fake.1588763362.51303 at yahoo.com>
Date: Wed, 06 May 2020 13:09:22 +0200
To: Test User <test at vmtom.com>
X-Cassandane-Unique: b73d082c465ef09890dc35e85d4e506b906d0a97


--boundary_1
Content-Type: text/plain; charset="UTF-8"

<main>plain</main>

--boundary_1
Content-Type: message/rfc822

Subject: bar
From: from at local
Date: Wed, 05 Oct 2016 14:59:07 +1100
To: to at local
Mime-Version: 1.0
Content-Type: multipart/alternative; boundary=boundary_2


--boundary_2
Content-Type: text/plain; charset="UTF-8"

<div>embeddedplain with <b>html</b>.</div>

--boundary_2
Content-Type: text/html; charset="UTF-8"

<div>embeddedhtml.</div>

--boundary_2--
C:
S: * 1 EXISTS
S: * 1 RECENT
S: 4 OK [APPENDUID 1588763363 1] Completed
=====> Instance::_find_binary[525] Found binary squatter in 
/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin
=====> Instance::_fork_command[1562] Running: 
"/root/rpmbuild/BUILDROOT/cyrus-imapd-3.2.0-1.el8.x86_64/usr/sbin/squatter" 
"-C" 
"/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129/conf/imapd.conf"
=====> Instance::_fork_command[1562] child pid=3154
=====> Instance::_fork_command[1562] setting core size limit to 104857600
10534602129/squatter[3154]: SQL backend defaulting to engine 'mysql'
10534602129/squatter[3154]: extractor_init((nil))
10534602129/squatter[3154]: indexing mailboxes
10534602129/squatter[3154]: indexing mailbox user.cassandane...
10534602129/squatter[3154]: Xapian committed 1 updates in 0.005897 sec
10534602129/squatter[3154]: done indexing mailboxes
10534602129/squatter[3154]: extractor_destroy(0x56118a562ba0)
=====> Cyrus::SearchFuzzy::test_striphtml_rfc822[75] Assert that HTML in 
top-level message isn't stripped
C: 5 search fuzzy body main
S: * SEARCH 1
S: 5 OK Completed (1 msgs in 0.001 secs)
=====> Cyrus::SearchFuzzy::test_striphtml_rfc822[75] Assert that HTML in 
embedded message plain text is stripped
C: 6 search fuzzy body div
S: * SEARCH 1
S: 6 OK Completed (1 msgs in 0.000 secs)
=====> Cyrus::TestCase::tear_down[93] (test_striphtml_rfc822) Beginning 
tear_down
C: 7 logout
S: * BYE LOGOUT received
S: 7 OK Completed
A: Release socket, fileno=57
=====> Instance::stop[773] stop main instance for test 
test_striphtml_rfc822: basedir 
/root/rpmbuild/BUILD/cyrus-imapd-3.2.0/cassandane/work/10534602129
=====> Instance::_stop_pid[1414] _stop_pid: sending signal TERM to 3139
=====> Util::Wait::timed_wait[1376] Waited 0.010099 sec for unknown 
condition
=====> Instance::__ANON__[1420] killing smtpd 3116
2020/05/06-13:09:23 Server closing!
=====> Instance::__ANON__[1420] killing notifyd 3135
=====> Instance::__ANON__[1459] killing smtpd 3116
=====> Cyrus::TestCase::tear_down[93] ---------- END 
test_striphtml_rfc822 ----------
=====> GenericDaemon::kill_processes_on_ports[808] checking for stray 
processes on ports: 19122 19123


Thanks a lot

Bye
Marco


More information about the Info-cyrus mailing list