search

cyrusimap / cassandane

Other
6 stars 11 forks source link

TesterJMAP: Recurse to find tests in t/ of JMAP::TestSuite #44

Closed wolfsage closed 6 years ago

wolfsage commented 6 years ago

Also, if the AUTHOR_TESTING environment variable is set, look in xt/

With this, test specification changes slightly:

Instead of:

TesterJMAP.previews

You'd do:

TesterJMAP.t:previews

(providing paths with / replaced with :)

elliefm commented 6 years ago

Not sure if I'm doing something wrong here...

$./testrunner.pl -f pretty TesterJMAP
Cyrus::TesterJMAP.t:getMessageUpdates-sinceState                        [FAILED]
Cyrus::TesterJMAP.t:basic                                               [FAILED]
Cyrus::TesterJMAP.t:getMessages-htmlBody                                [FAILED]
Cyrus::TesterJMAP.t:getMessages-header                                  [FAILED]
Cyrus::TesterJMAP.t:previews                                            [FAILED]

Time:  2 wallclock secs ( 0.08 usr  0.02 sys +  1.96 cusr  0.52 csys =  2.58 CPU)

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

There were 5 failures:
1) test_t:getMessageUpdates-sinceState(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x55fe4728e340), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726aa90), Test::Unit::Assertion::Boolean=SCALAR(0x55fe47297188), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726aa90), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726aa90)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726aa90)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726aa90), CODE(0x55fe47270ae0)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726aa90)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726aa90), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x55fe460ee4a8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), HASH(0x55fe47270588), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x55fe47270588)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x55fe4726a3a0)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x55fe4726a3a0)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x55fe460ead98)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), GLOB(0x55fe4602b820)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:getMessageUpdates-sinceState ----------
=====> Instance[1068] start main instance for test test_t:getMessageUpdates-sinceState: basedir /dev/shm/cass/025652B1
=====> Instance[1051] started smtpd as 31641
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/025652B1/conf/imapd.conf"
2018/03/09-13:56:52 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(31641)
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
Resolved [localhost]:9120 to [::1]:9120, IPv6
Resolved [localhost]:9120 to [127.0.0.1]:9120, IPv4
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
Binding to TCP port 9120 on host ::1 with IPv6
Binding to TCP port 9120 on host 127.0.0.1 with IPv4
=====> Instance[939] started saslauthd for /dev/shm/cass/025652B1 as 31646
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[966] started notifyd for /dev/shm/cass/025652B1 as 31647
=====> Instance[1836] opening socket /dev/shm/cass/025652B1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/025652B1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/025652B1/run/master.pid" "-d" "-M" "/dev/shm/cass/025652B1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9121
=====> Util::Wait[75] Waited 0.026841 sec for 127.0.0.1:9121 to be in LISTEN state
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9122
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9121
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:getMessageUpdates-sinceState: cyrus version 3.1.4-60-g89679d887
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/getMessageUpdates-sinceState.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241] #   Failed test 'called getMessageUpdates'

=====> Cyrus::TesterJMAP[241] #   at /home/ellie/fastmail/JMAP-TestSuite/t/getMessageUpdates-sinceState.t line 26.

=====> Cyrus::TesterJMAP[241] # HTTP/1.1 400 Bad Request

=====> Cyrus::TesterJMAP[241] # Connection: close

=====> Cyrus::TesterJMAP[241] # Date: Fri, 09 Mar 2018 02:56:53 GMT

=====> Cyrus::TesterJMAP[241] # Vary: Accept-Encoding

=====> Cyrus::TesterJMAP[241] # Content-Length: 470

=====> Cyrus::TesterJMAP[241] # Content-Type: text/html; charset=utf-8

=====> Cyrus::TesterJMAP[241] # Client-Date: Fri, 09 Mar 2018 02:56:53 GMT

=====> Cyrus::TesterJMAP[241] # Client-Peer: 127.0.0.1:9122

=====> Cyrus::TesterJMAP[241] # Client-Response-Num: 1

=====> Cyrus::TesterJMAP[241] # Title: 400 Bad Request

=====> Cyrus::TesterJMAP[241] # 

=====> Cyrus::TesterJMAP[241] # <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN" "http://www.w3.org/TR/html4/loose.dtd">

=====> Cyrus::TesterJMAP[241] # <html>

=====> Cyrus::TesterJMAP[241] #   <head>

=====> Cyrus::TesterJMAP[241] #     <title>400 Bad Request</title>

=====> Cyrus::TesterJMAP[241] #   </head>

=====> Cyrus::TesterJMAP[241] #   <body>

=====> Cyrus::TesterJMAP[241] #     <h1>Bad Request</h1>

=====> Cyrus::TesterJMAP[241] #     <p>JSON request body is not a JMAP Request object</p>

=====> Cyrus::TesterJMAP[241] #     <hr>

=====> Cyrus::TesterJMAP[241] #     <address>Cyrus-HTTP/3.1.4-60-g89679d887 Cyrus-SASL/2.1.27 LibXML2.9.4 OpenSSL/1.1 Zlib/1.2.8 SQLite/3.16.2 LibiCal/2.99 ICU4C/57.1 Jansson/2.9 Server at 127.0.0.1 Port 9122</address>

=====> Cyrus::TesterJMAP[241] #   </body>

=====> Cyrus::TesterJMAP[241] # </html>

=====> Cyrus::TesterJMAP[241] # Looks like you failed 1 test of 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 31675
=====> Instance[1054] killing smtpd 31641
2018/03/09-13:56:53 Server closing!
=====> Instance[942] killing saslauthd 31646
=====> Instance[1054] killing smtpd 31641
=====> Instance[969] killing notifyd 31647
=====> Instance[1054] killing smtpd 31641
=====> Instance[942] killing saslauthd 31646
=====> Cyrus::TestCase[724] ---------- END test_t:getMessageUpdates-sinceState ----------
=====> Daemon[385] checking for stray processes on ports: 9120 9121 9122

2) test_t:basic(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x55fe472aa860), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea270), Test::Unit::Assertion::Boolean=SCALAR(0x55fe472963e8), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea270), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea270)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea270)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea270), CODE(0x55fe47272a00)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea270)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea270), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x55fe460ee4a8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), HASH(0x55fe4726a250), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x55fe4726a250)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x55fe460ead68)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x55fe460ead68)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x55fe460ead98)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), GLOB(0x55fe4602b820)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:basic ----------
=====> Instance[1068] start main instance for test test_t:basic: basedir /dev/shm/cass/025652A1
=====> Instance[1051] started smtpd as 31640
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/025652A1/conf/imapd.conf"
2018/03/09-13:56:52 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(31640)
Resolved [localhost]:9100 to [::1]:9100, IPv6
Resolved [localhost]:9100 to [127.0.0.1]:9100, IPv4
Binding to TCP port 9100 on host ::1 with IPv6
Binding to TCP port 9100 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/025652A1 as 31659
=====> Instance[966] started notifyd for /dev/shm/cass/025652A1 as 31660
=====> Instance[1836] opening socket /dev/shm/cass/025652A1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/025652A1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/025652A1/run/master.pid" "-d" "-M" "/dev/shm/cass/025652A1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9101
=====> Util::Wait[75] Waited 0.02751 sec for 127.0.0.1:9101 to be in LISTEN state
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9102
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9101
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:basic: cyrus version 3.1.4-60-g89679d887
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/basic.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241] Can't locate object method "as_pairs" via package "JMAP::Tester::Result::Failure" at /home/ellie/fastmail/JMAP-TestSuite/t/basic.t line 18.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 31682
=====> Instance[1054] killing smtpd 31640
2018/03/09-13:56:53 Server closing!
=====> Instance[942] killing saslauthd 31659
=====> Instance[1054] killing smtpd 31640
=====> Instance[969] killing notifyd 31660
=====> Instance[1054] killing smtpd 31640
=====> Instance[942] killing saslauthd 31659
=====> Cyrus::TestCase[724] ---------- END test_t:basic ----------
=====> Daemon[385] checking for stray processes on ports: 9100 9101 9102

3) test_t:getMessages-htmlBody(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x55fe472b1a20), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea5b8), Test::Unit::Assertion::Boolean=SCALAR(0x55fe47299df8), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea5b8), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea5b8)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea5b8)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea5b8), CODE(0x55fe47270db0)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea5b8)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe460ea5b8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x55fe460ee4a8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), HASH(0x55fe472707c8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x55fe472707c8)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x55fe472704c8)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x55fe472704c8)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x55fe460ead98)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), GLOB(0x55fe4602b820)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:getMessages-htmlBody ----------
=====> Instance[1068] start main instance for test test_t:getMessages-htmlBody: basedir /dev/shm/cass/025652D1
=====> Instance[1051] started smtpd as 31644
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/025652D1/conf/imapd.conf"
2018/03/09-13:56:52 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(31644)
Resolved [localhost]:9160 to [::1]:9160, IPv6
Resolved [localhost]:9160 to [127.0.0.1]:9160, IPv4
Binding to TCP port 9160 on host ::1 with IPv6
Binding to TCP port 9160 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/025652D1 as 31671
=====> Instance[966] started notifyd for /dev/shm/cass/025652D1 as 31672
=====> Instance[1836] opening socket /dev/shm/cass/025652D1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/025652D1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/025652D1/run/master.pid" "-d" "-M" "/dev/shm/cass/025652D1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9161
=====> Util::Wait[75] Waited 0.023002 sec for 127.0.0.1:9161 to be in LISTEN state
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9162
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9162
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:getMessages-htmlBody: cyrus version 3.1.4-60-g89679d887
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/getMessages-htmlBody.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241] Can't locate object method "single_sentence" via package "JMAP::Tester::Result::Failure" at /home/ellie/fastmail/JMAP-TestSuite/lib/JMAP/TestSuite/Entity.pm line 102, <DATA> line 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 31689
=====> Instance[1054] killing smtpd 31644
2018/03/09-13:56:54 Server closing!
=====> Instance[942] killing saslauthd 31671
=====> Instance[1054] killing smtpd 31644
=====> Instance[969] killing notifyd 31672
=====> Instance[1054] killing smtpd 31644
=====> Instance[942] killing saslauthd 31671
=====> Cyrus::TestCase[724] ---------- END test_t:getMessages-htmlBody ----------
=====> Daemon[385] checking for stray processes on ports: 9160 9161 9162

4) test_t:getMessages-header(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x55fe472b2520), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a580), Test::Unit::Assertion::Boolean=SCALAR(0x55fe472ad1e8), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a580), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a580)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a580)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a580), CODE(0x55fe47270870)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a580)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a580), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x55fe460ee4a8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), HASH(0x55fe472706a8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x55fe472706a8)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x55fe4726a568)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x55fe4726a568)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x55fe460ead98)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), GLOB(0x55fe4602b820)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:getMessages-header ----------
=====> Instance[1068] start main instance for test test_t:getMessages-header: basedir /dev/shm/cass/025652C1
=====> Instance[1051] started smtpd as 31639
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/025652C1/conf/imapd.conf"
2018/03/09-13:56:52 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(31639)
Resolved [localhost]:9140 to [::1]:9140, IPv6
Resolved [localhost]:9140 to [127.0.0.1]:9140, IPv4
Binding to TCP port 9140 on host ::1 with IPv6
Binding to TCP port 9140 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/025652C1 as 31654
=====> Instance[966] started notifyd for /dev/shm/cass/025652C1 as 31656
=====> Instance[1836] opening socket /dev/shm/cass/025652C1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/025652C1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/025652C1/run/master.pid" "-d" "-M" "/dev/shm/cass/025652C1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9141
=====> Util::Wait[75] Waited 0.036246 sec for 127.0.0.1:9141 to be in LISTEN state
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9142
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9141
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:getMessages-header: cyrus version 3.1.4-60-g89679d887
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/getMessages-header.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241] Can't locate object method "single_sentence" via package "JMAP::Tester::Result::Failure" at /home/ellie/fastmail/JMAP-TestSuite/lib/JMAP/TestSuite/Entity.pm line 102, <DATA> line 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 31681
=====> Util::Wait[75] Waited 0.016203 sec for unknown condition
=====> Instance[1054] killing smtpd 31639
2018/03/09-13:56:54 Server closing!
=====> Instance[942] killing saslauthd 31654
=====> Instance[1054] killing smtpd 31639
=====> Instance[969] killing notifyd 31656
=====> Instance[1054] killing smtpd 31639
=====> Instance[942] killing saslauthd 31654
=====> Cyrus::TestCase[724] ---------- END test_t:getMessages-header ----------
=====> Daemon[385] checking for stray processes on ports: 9140 9141 9142

5) test_t:previews(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x55fe472c7c70), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a748), Test::Unit::Assertion::Boolean=SCALAR(0x55fe47296828), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a748), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a748)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a748)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a748), CODE(0x55fe472ae1b0)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a748)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x55fe4726a748), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x55fe460ee4a8), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), HASH(0x55fe47270ae0), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x55fe47270ae0)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x55fe4726a3a0)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x55fe4726a3a0)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x55fe460ead98)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), Test::Unit::Result=HASH(0x55fe460e5c60), Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x55fe460e5ac8), Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x55fe460e5a08), GLOB(0x55fe4602b820)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:previews ----------
=====> Instance[1068] start main instance for test test_t:previews: basedir /dev/shm/cass/025652B2
=====> Instance[1051] started smtpd as 31716
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/025652B2/conf/imapd.conf"
2018/03/09-13:56:53 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(31716)
Resolved [localhost]:9123 to [::1]:9123, IPv6
Resolved [localhost]:9123 to [127.0.0.1]:9123, IPv4
Binding to TCP port 9123 on host ::1 with IPv6
Binding to TCP port 9123 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/025652B2 as 31718
=====> Instance[966] started notifyd for /dev/shm/cass/025652B2 as 31719
=====> Instance[1836] opening socket /dev/shm/cass/025652B2/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/025652B2/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/025652B2/run/master.pid" "-d" "-M" "/dev/shm/cass/025652B2/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9124
=====> Util::Wait[75] Waited 0.039098 sec for 127.0.0.1:9124 to be in LISTEN state
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9125
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9125
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:previews: cyrus version 3.1.4-60-g89679d887
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/previews.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241] Can't locate object method "single_sentence" via package "JMAP::Tester::Result::Failure" at /home/ellie/fastmail/JMAP-TestSuite/lib/JMAP/TestSuite/Entity.pm line 102, <DATA> line 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 31728
=====> Util::Wait[75] Waited 0.010375 sec for unknown condition
=====> Instance[1054] killing smtpd 31716
2018/03/09-13:56:54 Server closing!
=====> Instance[942] killing saslauthd 31718
=====> Instance[1054] killing smtpd 31716
=====> Instance[969] killing notifyd 31719
=====> Instance[1054] killing smtpd 31716
=====> Instance[942] killing saslauthd 31718
=====> Cyrus::TestCase[724] ---------- END test_t:previews ----------
=====> Daemon[385] checking for stray processes on ports: 9123 9124 9125

Test was not successful.
elliefm commented 6 years ago

One of them seems to be choking here:

=====> Cyrus::TesterJMAP[241] Can't locate object method "as_pairs" via package "JMAP::Tester::Result::Failure" at /home/ellie/fastmail/JMAP-TestSuite/t/basic.t line 18.

and a few choke similarly like this:

=====> Cyrus::TesterJMAP[241] Can't locate object method "single_sentence" via package "JMAP::Tester::Result::Failure" at /home/ellie/fastmail/JMAP-TestSuite/lib/JMAP/TestSuite/Entity.pm line 102, <DATA> line 1.

Am I missing an unflagged dependency perhaps? I installed dependencies one at a time until it stopped whinging about them

wolfsage commented 6 years ago

I think you're running the wrong branch. You need https://github.com/wolfsage/JMAP-TestSuite/tree/new-spec

elliefm commented 6 years ago

Ahh, right, that helps!

Okay, I've added your remote, grabbed that branch, and installed dependencies until perl -c across the .pm and .t files stopped complaining...

Then back to Cassandane, and the TesterJMAP tests on the master branch now succeed. Progress! :)

Back to the PR branch, and a few more dependencies later, and I start running into things like this:

=====> Cyrus::TesterJMAP[241] sh: echo: I/O error

=====> Cyrus::TesterJMAP[241] # Failed test 'tests from /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/get/basic.t, line 307'

=====> Cyrus::TesterJMAP[241] # at /usr/share/perl5/Test/Routine/Runner.pm line 101.

=====> Cyrus::TesterJMAP[241] # Caught exception in subtest: Failed to run echo 'createmailbox user.jt-921e22e8-2724-11e8-bfc3-cf2bd5652a62@localhost' \

=====> Cyrus::TesterJMAP[241] #              | /usr/cyrus/bin/cyradm --notls -u admin -w testpw 127.0.0.1 --port 9121: sh: 2: /usr/cyrus/bin/cyradm: not found

=====> Cyrus::TesterJMAP[241] # 

=====> Cyrus::TesterJMAP[241] # Looks like you failed 1 test of 1.

Uh oh, is that a hardcoded path to cyradm? My Cassandane environment has Cyrus installed in /dev/shm/cyrus/main! Looking in the JMAP::TestSuite code, that looks like a default in a server adapter, so maybe it's my environment that still needs further configuration here? Or maybe TesterJMAP.pm needs to pass it down? (It's available from something like $instance->{basedir} iirc)

elliefm commented 6 years ago

Full output, in case it's helpful:

ellie@debian:wolfsage-TesterJMAP-recurse:~/fastmail/cassandane$./testrunner.pl TesterJMAP -f pretty
Cyrus::TesterJMAP.t:Mailbox:query:basic                                 [FAILED]
Cyrus::TesterJMAP.t:Mailbox:get:basic                                   [FAILED]
Cyrus::TesterJMAP.t:Mailbox:set:create                                  [FAILED]
Cyrus::TesterJMAP.t:Mailbox:changes:basic                               [FAILED]
Cyrus::TesterJMAP.t:basic                                               [  OK  ]
Cyrus::TesterJMAP.t:core:jmap-session-resource                          [FAILED]
Cyrus::TesterJMAP.t:getMessageUpdates-sinceState                        [  OK  ]
Cyrus::TesterJMAP.t:getMessages-header                                  [  OK  ]
Cyrus::TesterJMAP.t:previews                                            [  OK  ]
Cyrus::TesterJMAP.t:getMessages-htmlBody                                [  OK  ]

Time:  4 wallclock secs ( 0.10 usr  0.01 sys +  4.49 cusr  0.87 csys =  5.47 CPU)

!!!FAILURES!!!
Test Results:
Run: 10, Failures: 5, Errors: 0

There were 5 failures:
1) test_t:Mailbox:query:basic(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x558102e5ece8), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93cc0), Test::Unit::Assertion::Boolean=SCALAR(0x558102e43800), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93cc0), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93cc0)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93cc0)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93cc0), CODE(0x558102e1b0d8)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93cc0)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93cc0), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x558101c95a98), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), HASH(0x558102e1aca0), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x558102e1aca0)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x558102e11b88)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x558102e11b88)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x558102e1a8c8)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), Cassandane::Unit::TestPlan=HASH(0x558101c8d088), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), GLOB(0x558101bd2f00)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:Mailbox:query:basic ----------
=====> Instance[1068] start main instance for test test_t:Mailbox:query:basic: basedir /dev/shm/cass/012016C1
=====> Instance[1051] started smtpd as 14868
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/012016C1/conf/imapd.conf"
2018/03/14-12:20:16 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(14868)
Resolved [localhost]:9140 to [::1]:9140, IPv6
Resolved [localhost]:9140 to [127.0.0.1]:9140, IPv4
Binding to TCP port 9140 on host ::1 with IPv6
Binding to TCP port 9140 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/012016C1 as 14893
=====> Instance[966] started notifyd for /dev/shm/cass/012016C1 as 14894
=====> Instance[1836] opening socket /dev/shm/cass/012016C1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/012016C1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/012016C1/run/master.pid" "-d" "-M" "/dev/shm/cass/012016C1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9141
=====> Util::Wait[75] Waited 0.027707 sec for 127.0.0.1:9141 to be in LISTEN state
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9142
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9142
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:Mailbox:query:basic: cyrus version 3.1.4-66-g0121dfc70
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/query/basic.t"
=====> Cyrus::TesterJMAP[241] # Failed test 'tests from /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/query/basic.t, line 484'

=====> Cyrus::TesterJMAP[241] # at /usr/share/perl5/Test/Routine/Runner.pm line 101.

=====> Cyrus::TesterJMAP[241] # Caught exception in subtest: Failed to run echo 'createmailbox user.jt-db1db12e-2725-11e8-88b7-92dcaa5e201e@localhost' \

=====> Cyrus::TesterJMAP[241] #              | /usr/cyrus/bin/cyradm --notls -u admin -w testpw 127.0.0.1 --port 9142: sh: 2: /usr/cyrus/bin/cyradm: not found

=====> Cyrus::TesterJMAP[241] # 

=====> Cyrus::TesterJMAP[241] # Looks like you failed 1 test of 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 14910
=====> Instance[1054] killing smtpd 14868
2018/03/14-12:20:17 Server closing!
=====> Instance[942] killing saslauthd 14893
=====> Instance[1054] killing smtpd 14868
=====> Instance[969] killing notifyd 14894
=====> Instance[1054] killing smtpd 14868
=====> Instance[942] killing saslauthd 14893
=====> Cyrus::TestCase[724] ---------- END test_t:Mailbox:query:basic ----------
=====> Daemon[385] checking for stray processes on ports: 9140 9141 9142

2) test_t:Mailbox:get:basic(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x558102e5ce48), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17870), Test::Unit::Assertion::Boolean=SCALAR(0x558102e3f2c0), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17870), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17870)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17870)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17870), CODE(0x558102e1b168)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17870)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17870), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x558101c95a98), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), HASH(0x558102e1ab80), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x558102e1ab80)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x558102e11c00)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x558102e11c00)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x558102e1a8c8)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), Cassandane::Unit::TestPlan=HASH(0x558101c8d088), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), GLOB(0x558101bd2f00)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:Mailbox:get:basic ----------
=====> Instance[1068] start main instance for test test_t:Mailbox:get:basic: basedir /dev/shm/cass/012016B1
=====> Instance[1051] started smtpd as 14863
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/012016B1/conf/imapd.conf"
2018/03/14-12:20:16 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(14863)
Resolved [localhost]:9120 to [::1]:9120, IPv6
Resolved [localhost]:9120 to [127.0.0.1]:9120, IPv4
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/012016B1 as 14870
Binding to TCP port 9120 on host ::1 with IPv6
Binding to TCP port 9120 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[966] started notifyd for /dev/shm/cass/012016B1 as 14871
=====> Instance[1836] opening socket /dev/shm/cass/012016B1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/012016B1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/012016B1/run/master.pid" "-d" "-M" "/dev/shm/cass/012016B1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9121
=====> Util::Wait[75] Waited 0.027666 sec for 127.0.0.1:9121 to be in LISTEN state
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9122
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9121
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:Mailbox:get:basic: cyrus version 3.1.4-66-g0121dfc70
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/get/basic.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241] sh: echo: I/O error

=====> Cyrus::TesterJMAP[241] # Failed test 'tests from /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/get/basic.t, line 307'

=====> Cyrus::TesterJMAP[241] # at /usr/share/perl5/Test/Routine/Runner.pm line 101.

=====> Cyrus::TesterJMAP[241] # Caught exception in subtest: Failed to run echo 'createmailbox user.jt-db36b7aa-2725-11e8-8081-e43e871b255e@localhost' \

=====> Cyrus::TesterJMAP[241] #              | /usr/cyrus/bin/cyradm --notls -u admin -w testpw 127.0.0.1 --port 9121: sh: 2: /usr/cyrus/bin/cyradm: not found

=====> Cyrus::TesterJMAP[241] # 

=====> Cyrus::TesterJMAP[241] # Looks like you failed 1 test of 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 14903
=====> Util::Wait[75] Waited 0.010167 sec for unknown condition
=====> Instance[1054] killing smtpd 14863
2018/03/14-12:20:18 Server closing!
=====> Instance[942] killing saslauthd 14870
=====> Instance[1054] killing smtpd 14863
=====> Instance[969] killing notifyd 14871
=====> Instance[1054] killing smtpd 14863
=====> Instance[942] killing saslauthd 14870
=====> Cyrus::TestCase[724] ---------- END test_t:Mailbox:get:basic ----------
=====> Daemon[385] checking for stray processes on ports: 9120 9121 9122

3) test_t:Mailbox:set:create(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x558102e55fe8), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93978), Test::Unit::Assertion::Boolean=SCALAR(0x558102e43ad0), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93978), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93978)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93978)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93978), CODE(0x558102e1b1e0)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93978)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x558101c93978), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x558101c95a98), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), HASH(0x558102e1adc0), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x558102e1adc0)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x558102e1aac0)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x558102e1aac0)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x558102e1a8c8)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), Cassandane::Unit::TestPlan=HASH(0x558101c8d088), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), GLOB(0x558101bd2f00)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:Mailbox:set:create ----------
=====> Instance[1068] start main instance for test test_t:Mailbox:set:create: basedir /dev/shm/cass/012016D1
=====> Instance[1051] started smtpd as 14867
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/012016D1/conf/imapd.conf"
2018/03/14-12:20:16 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(14867)
Resolved [localhost]:9160 to [::1]:9160, IPv6
Resolved [localhost]:9160 to [127.0.0.1]:9160, IPv4
Binding to TCP port 9160 on host ::1 with IPv6
Binding to TCP port 9160 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/012016D1 as 14889
=====> Instance[966] started notifyd for /dev/shm/cass/012016D1 as 14890
=====> Instance[1836] opening socket /dev/shm/cass/012016D1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/012016D1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/012016D1/run/master.pid" "-d" "-M" "/dev/shm/cass/012016D1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9161
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9162
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9161
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:Mailbox:set:create: cyrus version 3.1.4-66-g0121dfc70
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/set/create.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241]             #   Failed test 'Our mailbox looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/set/create.t line 95.

=====> Cyrus::TesterJMAP[241]             # Comparing (Part 2 of 2 in $data->{"sortOrder"}) as a number

=====> Cyrus::TesterJMAP[241]             #    got : 10

=====> Cyrus::TesterJMAP[241]             # expect : 0

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 3.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'Confirm our name/defaults good'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/set/create.t line 111.

=====> Cyrus::TesterJMAP[241]     # Failed test 'Mailbox/set create with defaults omitted'

=====> Cyrus::TesterJMAP[241]     # at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/set/create.t line 112.

=====> Cyrus::TesterJMAP[241] # Failed test 'tests from /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/set/create.t, line 201'

=====> Cyrus::TesterJMAP[241] # at /usr/share/perl5/Test/Routine/Runner.pm line 101.

=====> Cyrus::TesterJMAP[241] # Looks like you failed 1 test of 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 14914
=====> Instance[1054] killing smtpd 14867
2018/03/14-12:20:18 Server closing!
=====> Instance[942] killing saslauthd 14889
=====> Instance[1054] killing smtpd 14867
=====> Instance[969] killing notifyd 14890
=====> Instance[1054] killing smtpd 14867
=====> Instance[942] killing saslauthd 14889
=====> Cyrus::TestCase[724] ---------- END test_t:Mailbox:set:create ----------
=====> Daemon[385] checking for stray processes on ports: 9160 9161 9162

4) test_t:Mailbox:changes:basic(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x558102e5d770), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17bb8), Test::Unit::Assertion::Boolean=SCALAR(0x558102e5d068), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17bb8), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17bb8)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17bb8)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17bb8), CODE(0x558102e1b090)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17bb8)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17bb8), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x558101c95a98), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), HASH(0x558102e18248), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x558102e18248)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x558102e1a898)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x558102e1a898)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x558102e1a8c8)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), Cassandane::Unit::TestPlan=HASH(0x558101c8d088), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), GLOB(0x558101bd2f00)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:Mailbox:changes:basic ----------
=====> Instance[1068] start main instance for test test_t:Mailbox:changes:basic: basedir /dev/shm/cass/012016A1
=====> Instance[1051] started smtpd as 14864
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/012016A1/conf/imapd.conf"
2018/03/14-12:20:16 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(14864)
Resolved [localhost]:9100 to [::1]:9100, IPv6
Resolved [localhost]:9100 to [127.0.0.1]:9100, IPv4
Binding to TCP port 9100 on host ::1 with IPv6
Binding to TCP port 9100 on host 127.0.0.1 with IPv4
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
=====> Instance[939] started saslauthd for /dev/shm/cass/012016A1 as 14877
=====> Instance[966] started notifyd for /dev/shm/cass/012016A1 as 14878
=====> Instance[1836] opening socket /dev/shm/cass/012016A1/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/012016A1/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/012016A1/run/master.pid" "-d" "-M" "/dev/shm/cass/012016A1/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9101
=====> Util::Wait[75] Waited 0.028704 sec for 127.0.0.1:9101 to be in LISTEN state
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9102
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9101
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:Mailbox:changes:basic: cyrus version 3.1.4-66-g0121dfc70
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 36.

=====> Cyrus::TesterJMAP[241]         # Comparing $data->{"changed"} as a string

=====> Cyrus::TesterJMAP[241]         #    got : 'ARRAY(0x55ee76a124c8)'

=====> Cyrus::TesterJMAP[241]         # expect : undef

=====> Cyrus::TesterJMAP[241]     # Failed test 'Mailbox/changes with no changes'

=====> Cyrus::TesterJMAP[241]     # at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 54.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 75.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"destroyed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76abccb8)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 4.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'created entities show up in changed'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 87.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 118.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"destroyed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76abc8f8)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 5.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'updated entities show up in changed'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 130.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 159.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"changed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76ace598)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 5.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'destroyed entities show up in destroyed'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 171.

=====> Cyrus::TesterJMAP[241]     # Failed test 'Mailbox/changes with changes'

=====> Cyrus::TesterJMAP[241]     # at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 172.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 209.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"destroyed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76abe7d8)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # [

=====> Cyrus::TesterJMAP[241]             #   [

=====> Cyrus::TesterJMAP[241]             #     'Mailbox/changes',

=====> Cyrus::TesterJMAP[241]             #     {

=====> Cyrus::TesterJMAP[241]             #       'accountId' => 'cassandane',

=====> Cyrus::TesterJMAP[241]             #       'changed' => [

=====> Cyrus::TesterJMAP[241]             #         '7864bef4-e66d-406e-8e25-dd46caf594e7'

=====> Cyrus::TesterJMAP[241]             #       ],

=====> Cyrus::TesterJMAP[241]             #       'changedProperties' => undef,

=====> Cyrus::TesterJMAP[241]             #       'destroyed' => [],

=====> Cyrus::TesterJMAP[241]             #       'hasMoreChanges' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' ),

=====> Cyrus::TesterJMAP[241]             #       'newState' => '26',

=====> Cyrus::TesterJMAP[241]             #       'oldState' => '24'

=====> Cyrus::TesterJMAP[241]             #     },

=====> Cyrus::TesterJMAP[241]             #     'y'

=====> Cyrus::TesterJMAP[241]             #   ]

=====> Cyrus::TesterJMAP[241]             # ]

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 3.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'changes from start state'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 224.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 240.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"destroyed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76aeee00)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 2.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'changes from middle state to final state'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 252.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 267.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"destroyed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76acde60)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 2.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'final state says no changes'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 279.

=====> Cyrus::TesterJMAP[241]     # Failed test 'maxChanges and hasMoreChanges'

=====> Cyrus::TesterJMAP[241]     # at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 280.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 306.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"destroyed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76d237c0)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # [

=====> Cyrus::TesterJMAP[241]             #   [

=====> Cyrus::TesterJMAP[241]             #     'Mailbox/changes',

=====> Cyrus::TesterJMAP[241]             #     {

=====> Cyrus::TesterJMAP[241]             #       'accountId' => 'cassandane',

=====> Cyrus::TesterJMAP[241]             #       'changed' => [

=====> Cyrus::TesterJMAP[241]             #         'c72fc187-77f5-4374-b7cf-5fff84004409'

=====> Cyrus::TesterJMAP[241]             #       ],

=====> Cyrus::TesterJMAP[241]             #       'changedProperties' => [

=====> Cyrus::TesterJMAP[241]             #         'totalEmails',

=====> Cyrus::TesterJMAP[241]             #         'unreadEmails',

=====> Cyrus::TesterJMAP[241]             #         'totalThreads',

=====> Cyrus::TesterJMAP[241]             #         'unreadThreads'

=====> Cyrus::TesterJMAP[241]             #       ],

=====> Cyrus::TesterJMAP[241]             #       'destroyed' => [],

=====> Cyrus::TesterJMAP[241]             #       'hasMoreChanges' => bless( do{\(my $o = 0)}, 'JSON::PP::Boolean' ),

=====> Cyrus::TesterJMAP[241]             #       'newState' => '40',

=====> Cyrus::TesterJMAP[241]             #       'oldState' => '36'

=====> Cyrus::TesterJMAP[241]             #     },

=====> Cyrus::TesterJMAP[241]             #     'ai'

=====> Cyrus::TesterJMAP[241]             #   ]

=====> Cyrus::TesterJMAP[241]             # ]

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 6.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'Only counts changed, should get changedProperties'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 324.

=====> Cyrus::TesterJMAP[241] Use of uninitialized value in string eq at /usr/share/perl5/Test/Deep/String.pm line 22.

=====> Cyrus::TesterJMAP[241]             #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]             #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 348.

=====> Cyrus::TesterJMAP[241]             # Comparing $data->{"destroyed"} as a string

=====> Cyrus::TesterJMAP[241]             #    got : 'ARRAY(0x55ee76cfc878)'

=====> Cyrus::TesterJMAP[241]             # expect : undef

=====> Cyrus::TesterJMAP[241]             # [

=====> Cyrus::TesterJMAP[241]             #   [

=====> Cyrus::TesterJMAP[241]             #     'Mailbox/changes',

=====> Cyrus::TesterJMAP[241]             #     {

=====> Cyrus::TesterJMAP[241]             #       'accountId' => 'cassandane',

=====> Cyrus::TesterJMAP[241]             #       'changed' => [

=====> Cyrus::TesterJMAP[241]             #         '3eb9d962-3d07-4d88-835a-89e3d65eb0fa',

=====> Cyrus::TesterJMAP[241]             #         '8048d369-b738-4e3c-bbed-3241176ab74e'

=====> Cyrus::TesterJMAP[241]             #       ],

=====> Cyrus::TesterJMAP[241]             #       'changedProperties' => undef,

=====> Cyrus::TesterJMAP[241]             #       'destroyed' => [],

=====> Cyrus::TesterJMAP[241]             #       'hasMoreChanges' => bless( do{\(my $o = 0)}, 'JSON::PP::Boolean' ),

=====> Cyrus::TesterJMAP[241]             #       'newState' => '49',

=====> Cyrus::TesterJMAP[241]             #       'oldState' => '43'

=====> Cyrus::TesterJMAP[241]             #     },

=====> Cyrus::TesterJMAP[241]             #     'aq'

=====> Cyrus::TesterJMAP[241]             #   ]

=====> Cyrus::TesterJMAP[241]             # ]

=====> Cyrus::TesterJMAP[241]             # Looks like you failed 1 test of 7.

=====> Cyrus::TesterJMAP[241]         #   Failed test 'Counts and other things changed, should not get'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 366.

=====> Cyrus::TesterJMAP[241]     # Failed test 'changedProperties'

=====> Cyrus::TesterJMAP[241]     # at /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t line 367.

=====> Cyrus::TesterJMAP[241] # Failed test 'tests from /home/ellie/fastmail/JMAP-TestSuite/t/Mailbox/changes/basic.t, line 369'

=====> Cyrus::TesterJMAP[241] # at /usr/share/perl5/Test/Routine/Runner.pm line 101.

=====> Cyrus::TesterJMAP[241] # Looks like you failed 1 test of 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 14895
=====> Util::Wait[75] Waited 0.025491 sec for unknown condition
=====> Instance[1054] killing smtpd 14864
2018/03/14-12:20:18 Server closing!
=====> Instance[942] killing saslauthd 14877
=====> Instance[1054] killing smtpd 14864
=====> Instance[969] killing notifyd 14878
=====> Instance[1054] killing smtpd 14864
=====> Instance[942] killing saslauthd 14877
=====> Cyrus::TestCase[724] ---------- END test_t:Mailbox:changes:basic ----------
=====> Daemon[385] checking for stray processes on ports: 9100 9101 9102

5) test_t:core:jmap-session-resource(Cassandane::Cyrus::TesterJMAP)
 Boolean assertion failed at /usr/share/perl5/Test/Unit/Exception.pm line 13.
    Test::Unit::Exception::throw_new(Test::Unit::Failure=HASH(0x558102e25f38), "-package", "Cassandane::Cyrus::TesterJMAP", "-file", "Cassandane/Cyrus/TesterJMAP.pm", "-line", 257, "-object", ...) called at /usr/share/perl5/Test/Unit/Assert.pm line 85
    Test::Unit::Assert::do_assertion(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17f00), Test::Unit::Assertion::Boolean=SCALAR(0x558102e3f6b0), "Cassandane::Cyrus::TesterJMAP", "Cassandane/Cyrus/TesterJMAP.pm", 257) called at /usr/share/perl5/Test/Unit/Assert.pm line 19
    Test::Unit::Assert::assert(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17f00), 0) called at Cassandane/Cyrus/TesterJMAP.pm line 257
    Cassandane::Cyrus::TesterJMAP::run_test(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17f00)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 61
    Test::Unit::TestCase::run_bare(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17f00)) called at /usr/share/perl5/Test/Unit/Result.pm line 103
    Test::Unit::Result::__ANON__() called at /usr/share/perl5/Test/Unit/Result.pm line 119
    Test::Unit::Result::run_protected(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17f00), CODE(0x558102e33958)) called at /usr/share/perl5/Test/Unit/Result.pm line 107
    Test::Unit::Result::run(Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17f00)) called at /usr/share/perl5/Test/Unit/TestCase.pm line 51
    Test::Unit::TestCase::run(Cassandane::Cyrus::TesterJMAP=HASH(0x558102e17f00), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestSuite.pm line 278
    Test::Unit::TestSuite::run(Test::Unit::TestSuite=HASH(0x558101c95a98), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at Cassandane/Unit/TestPlan.pm line 749
    Cassandane::Unit::TestPlan::_run_workitem(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), HASH(0x558102e1b168), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), 0) called at Cassandane/Unit/TestPlan.pm line 865
    Cassandane::Unit::TestPlan::__ANON__(HASH(0x558102e1b168)) called at Cassandane/Unit/TestPlan.pm line 205
    Cassandane::Unit::Worker::_mainloop(Cassandane::Unit::Worker=HASH(0x558102e11c00)) called at Cassandane/Unit/TestPlan.pm line 165
    Cassandane::Unit::Worker::start(Cassandane::Unit::Worker=HASH(0x558102e11c00)) called at Cassandane/Unit/TestPlan.pm line 310
    Cassandane::Unit::WorkerPool::start(Cassandane::Unit::WorkerPool=HASH(0x558102e1a8c8)) called at Cassandane/Unit/TestPlan.pm line 869
    Cassandane::Unit::TestPlan::run(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), Test::Unit::Result=HASH(0x558101c8d2e0), Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148)) called at /usr/share/perl5/Test/Unit/TestRunner.pm line 54
    Test::Unit::TestRunner::do_run(Cassandane::Unit::RunnerPretty=HASH(0x558101c8d148), Cassandane::Unit::TestPlan=HASH(0x558101c8d088), 0) called at ./testrunner.pl line 126
    main::__ANON__(Cassandane::Unit::TestPlan=HASH(0x558101c8d088), GLOB(0x558101bd2f00)) called at ./testrunner.pl line 300

Annotations:
=====> Cyrus::TestCase[565] ---------- BEGIN test_t:core:jmap-session-resource ----------
=====> Instance[1068] start main instance for test test_t:core:jmap-session-resource: basedir /dev/shm/cass/012016B2
=====> Instance[1051] started smtpd as 14968
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[474] Found binary cyr_buildinfo in /dev/shm/cyrus/main/sbin
=====> Instance[1573] Running: "/dev/shm/cyrus/main/sbin/cyr_buildinfo" "-C" "/dev/shm/cass/012016B2/conf/imapd.conf"
2018/03/14-12:20:18 Cassandane::Net::SMTPServer (type Net::Server::PreForkSimple) starting! pid(14968)
Resolved [localhost]:9123 to [::1]:9123, IPv6
Resolved [localhost]:9123 to [127.0.0.1]:9123, IPv4
=====> Instance[474] Found binary ctl_cyrusdb in /dev/shm/cyrus/main/sbin
Binding to TCP port 9123 on host ::1 with IPv6
=====> Instance[474] Found binary httpd in /dev/shm/cyrus/main/libexec
Binding to TCP port 9123 on host 127.0.0.1 with IPv4
=====> Instance[474] Found binary imapd in /dev/shm/cyrus/main/libexec
Group Not Defined.  Defaulting to EGID '123 8 123'
User Not Defined.  Defaulting to EUID '117'
=====> Instance[939] started saslauthd for /dev/shm/cass/012016B2 as 14973
=====> Instance[966] started notifyd for /dev/shm/cass/012016B2 as 14977
=====> Instance[1836] opening socket /dev/shm/cass/012016B2/run/mux
=====> Instance[474] Found binary master in /dev/shm/cyrus/main/libexec
=====> Instance[1573] Running: "/dev/shm/cyrus/main/libexec/master" "-C" "/dev/shm/cass/012016B2/conf/imapd.conf" "-l" "255" "-p" "/dev/shm/cass/012016B2/run/master.pid" "-d" "-M" "/dev/shm/cass/012016B2/conf/cyrus.conf"
=====> Instance[891] _start_master: waiting for PID file
=====> Instance[894] _start_master: PID file present and correct
=====> Instance[906] _start_master: PID waiting for services
=====> Daemon[356] is_listening: service http is listening on 127.0.0.1:9124
=====> Util::Wait[75] Waited 0.031236 sec for 127.0.0.1:9124 to be in LISTEN state
=====> Daemon[356] is_listening: service imap is listening on 127.0.0.1:9125
=====> Instance[917] _start_master: all services listening
=====> Instance[993] create user cassandane
=====> Util::Socket[61] create_client_socket INET host=127.0.0.1 port=9125
=====> Instance[1851] authdaemon connection: admin testpw imap 
=====> Instance[1103] started main instance for test test_t:core:jmap-session-resource: cyrus version 3.1.4-66-g0121dfc70
=====> Cyrus::TestCase[572] Calling test function
=====> Instance[1573] Running: "perl" "-I" "/home/ellie/fastmail/JMAP-TestSuite/lib" "/home/ellie/fastmail/JMAP-TestSuite/t/core/jmap-session-resource.t"
=====> Instance[1851] authdaemon connection: cassandane pass http 
=====> Cyrus::TesterJMAP[241]         #   Failed test 'Response looks good'

=====> Cyrus::TesterJMAP[241]         #   at /home/ellie/fastmail/JMAP-TestSuite/t/core/jmap-session-resource.t line 29.

=====> Cyrus::TesterJMAP[241]         # Comparing hash keys of $data->{"accounts"}{"cassandane"}

=====> Cyrus::TesterJMAP[241]         # Extra: 'hasDataFor'

=====> Cyrus::TesterJMAP[241]         # {

=====> Cyrus::TesterJMAP[241]         #   'accounts' => {

=====> Cyrus::TesterJMAP[241]         #     'cassandane' => {

=====> Cyrus::TesterJMAP[241]         #       'hasDataFor' => 'mail',

=====> Cyrus::TesterJMAP[241]         #       'isPrimary' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' ),

=====> Cyrus::TesterJMAP[241]         #       'isReadOnly' => bless( do{\(my $o = 0)}, 'JSON::PP::Boolean' ),

=====> Cyrus::TesterJMAP[241]         #       'name' => 'cassandane'

=====> Cyrus::TesterJMAP[241]         #     }

=====> Cyrus::TesterJMAP[241]         #   },

=====> Cyrus::TesterJMAP[241]         #   'apiUrl' => '/jmap/',

=====> Cyrus::TesterJMAP[241]         #   'capabilities' => {

=====> Cyrus::TesterJMAP[241]         #     'ietf:jmap' => {

=====> Cyrus::TesterJMAP[241]         #       'collationAlgorithms' => [],

=====> Cyrus::TesterJMAP[241]         #       'maxCallsInRequest' => 50,

=====> Cyrus::TesterJMAP[241]         #       'maxConcurrentRequests' => 5,

=====> Cyrus::TesterJMAP[241]         #       'maxConcurrentUpload' => 5,

=====> Cyrus::TesterJMAP[241]         #       'maxObjectsInGet' => 4096,

=====> Cyrus::TesterJMAP[241]         #       'maxObjectsInSet' => 4096,

=====> Cyrus::TesterJMAP[241]         #       'maxSizeRequest' => 10485760,

=====> Cyrus::TesterJMAP[241]         #       'maxSizeUpload' => 1073741824

=====> Cyrus::TesterJMAP[241]         #     },

=====> Cyrus::TesterJMAP[241]         #     'ietf:jmapmail' => {

=====> Cyrus::TesterJMAP[241]         #       'emailsListSortOptions' => [

=====> Cyrus::TesterJMAP[241]         #         'receivedAt',

=====> Cyrus::TesterJMAP[241]         #         'from',

=====> Cyrus::TesterJMAP[241]         #         'id',

=====> Cyrus::TesterJMAP[241]         #         'emailstate',

=====> Cyrus::TesterJMAP[241]         #         'size',

=====> Cyrus::TesterJMAP[241]         #         'subject',

=====> Cyrus::TesterJMAP[241]         #         'to',

=====> Cyrus::TesterJMAP[241]         #         'hasKeyword',

=====> Cyrus::TesterJMAP[241]         #         'someInThreadHaveKeyword'

=====> Cyrus::TesterJMAP[241]         #       ],

=====> Cyrus::TesterJMAP[241]         #       'maxDelayedSend' => 0,

=====> Cyrus::TesterJMAP[241]         #       'maxMailboxesPerEmail' => undef,

=====> Cyrus::TesterJMAP[241]         #       'maxSizeAttachmentsPerEmail' => 10485760,

=====> Cyrus::TesterJMAP[241]         #       'submissionExtensions' => {}

=====> Cyrus::TesterJMAP[241]         #     }

=====> Cyrus::TesterJMAP[241]         #   },

=====> Cyrus::TesterJMAP[241]         #   'downloadUrl' => '/jmap/download/{accountId}/{blobId}/{name}',

=====> Cyrus::TesterJMAP[241]         #   'uploadUrl' => '/jmap/upload/{accountId}/',

=====> Cyrus::TesterJMAP[241]         #   'username' => 'cassandane'

=====> Cyrus::TesterJMAP[241]         # }

=====> Cyrus::TesterJMAP[241]     # Failed test 'GETting jmap api gives us data and capabilities about the server'

=====> Cyrus::TesterJMAP[241]     # at /home/ellie/fastmail/JMAP-TestSuite/t/core/jmap-session-resource.t line 60.

=====> Cyrus::TesterJMAP[241] # Failed test 'tests from /home/ellie/fastmail/JMAP-TestSuite/t/core/jmap-session-resource.t, line 62'

=====> Cyrus::TesterJMAP[241] # at /usr/share/perl5/Test/Routine/Runner.pm line 101.

=====> Cyrus::TesterJMAP[241] # Looks like you failed 1 test of 1.

=====> Cyrus::TestCase[679] Beginning tear_down
=====> Instance[1310] stop
=====> Instance[1272] _stop_pid: sending signal 15 to 14988
=====> Instance[1054] killing smtpd 14968
2018/03/14-12:20:19 Server closing!
=====> Instance[942] killing saslauthd 14973
=====> Instance[1054] killing smtpd 14968
=====> Instance[969] killing notifyd 14977
=====> Instance[1054] killing smtpd 14968
=====> Instance[942] killing saslauthd 14973
=====> Cyrus::TestCase[724] ---------- END test_t:core:jmap-session-resource ----------
=====> Daemon[385] checking for stray processes on ports: 9123 9124 9125

Test was not successful.
elliefm commented 6 years ago

(I think some of those "got: [array] / expected: undef" errors might be from the recent change wrt returning [] instead of undef in some places, so I haven't dug into those in any depth yet. But the /usr/cyrus path caught my eye!)

elliefm commented 6 years ago

It may also be worth noting that I needed to package up Test::Routine from CPAN, even though Debian already has libtest-routine-perl, because Debian's is at 0.023 but JMAP::TestSuite explicitly wants 0.025.

elliefm commented 6 years ago

This tidies up the double-newlines in the error report:

diff --git a/Cassandane/Cyrus/TesterJMAP.pm b/Cassandane/Cyrus/TesterJMAP.pm
index 725bbab..bd8791f 100644
--- a/Cassandane/Cyrus/TesterJMAP.pm
+++ b/Cassandane/Cyrus/TesterJMAP.pm
@@ -238,6 +238,7 @@ sub run_test
             open FH, '<', $errfile
                 or die "Cannot open $errfile for reading: $!";
             while (readline FH) {
+                chomp;
                 xlog $_;
             }
             close FH;
wolfsage commented 6 years ago

Yeah, I need to pass in the path to cyradm (and maybe do something less janky in the future). Can do so tomorrow

elliefm commented 6 years ago

If you rebase onto master, which now has a correct .travis.yml, we should be able to get rid of that icky "All checks have failed"! :)

elliefm commented 6 years ago

Happy with this, in the sense that the TesterJMAP infrastructure for running JMAP::TestSuite now looks good.

(Still some expected failures within JMAP::TestSuite, discussed out of band, but from the point of view of this PR, those are "upstream problems".)