Open lmwnshn opened 3 years ago
Hit again here:
http://jenkins.db.cs.cmu.edu:8080/blue/organizations/jenkins/terrier/detail/PR-1589/5/pipeline
+++ ==================================================================================================== +++
+++ TEST JUNIT +++
05-24-2021 18:44:08,675 [db_server.py:89] INFO : Running: /jenkins/workspace/terrier_PR-1589/build/bin/noisepage -wal_file_path=/jenkins/workspace/terrier_PR-1589/build/bin/noisepage-wal.log -pipeline_metrics_enable=True -pipeline_metrics_sample_rate=100 -counters_enable=True -query_trace_metrics_enable=True -compiled_query_execution=True -bytecode_handlers_path=/jenkins/workspace/terrier_PR-1589/build/bin/bytecode_handlers_ir.bc
05-24-2021 18:44:08,678 [db_server.py:94] INFO : Ran: /jenkins/workspace/terrier_PR-1589/build/bin/noisepage -wal_file_path=/jenkins/workspace/terrier_PR-1589/build/bin/noisepage-wal.log -pipeline_metrics_enable=True -pipeline_metrics_sample_rate=100 -counters_enable=True -query_trace_metrics_enable=True -compiled_query_execution=True -bytecode_handlers_path=/jenkins/workspace/terrier_PR-1589/build/bin/bytecode_handlers_ir.bc [PID=15667]
05-24-2021 18:44:08,678 [db_server.py:99] INFO : Waiting until DBMS stdout contains: NoisePage - Self-Driving Database Management System [port=15721] [PID=15667]
05-24-2021 18:44:08,896 [db_server.py:107] INFO : DB process is verified as running in 0.22 sec.
05-24-2021 18:44:08,896 [db_server.py:110] INFO : ************ DB Logs Start ************
[2021-05-24 18:44:08.866] [storage_logger] [info] Default transaction policy: DURABILITY SYNC REPLICATION DISABLE
[2021-05-24 18:44:08.895] [network_logger] [info] Listening on networked socket with port 15721 [PID=15667]
[2021-05-24 18:44:08.895] [network_logger] [info] Listening on Unix domain socket with port 15721 [PID=15667]
NoisePage - Self-Driving Database Management System [port=15721] [PID=15667]
05-24-2021 18:44:08,896 [db_server.py:111] INFO : ************* DB Logs End *************
05-24-2021 18:44:08,896 [test_server.py:106] INFO : Logging output (overwrite) to: /tmp/noisepage-junit_log.txt
05-24-2021 18:44:08,898 [common.py:49] INFO : Running: ant test-unit
05-24-2021 18:44:20,221 [common.py:153] INFO : Buildfile: /jenkins/workspace/terrier_PR-1589/script/testing/junit/build.xml
05-24-2021 18:44:20,222 [common.py:153] INFO :
05-24-2021 18:44:20,222 [common.py:153] INFO : compile:
05-24-2021 18:44:20,222 [common.py:153] INFO : [javac] Compiling 1 source file to /jenkins/workspace/terrier_PR-1589/script/testing/junit/out
05-24-2021 18:44:20,222 [common.py:153] INFO : [javac] Note: /jenkins/workspace/terrier_PR-1589/script/testing/junit/src/moglib/CommandLine.java uses unchecked or unsafe operations.
05-24-2021 18:44:20,222 [common.py:153] INFO : [javac] Note: Recompile with -Xlint:unchecked for details.
05-24-2021 18:44:20,222 [common.py:153] INFO :
05-24-2021 18:44:20,222 [common.py:153] INFO : test-unit:
05-24-2021 18:44:20,222 [common.py:153] INFO : [java] ���
05-24-2021 18:44:20,222 [common.py:153] INFO : [java] ������ JUnit Jupiter ���
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ JUnit Vintage ���
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ WireTest ���
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ��� ������ testDouble ���
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ TrafficCopTest ���
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ test_DisconnectAbort ��� expected:<[An I/O error occurred while sending to the backen]d.> but was:<[ERROR: Query faile]d.>
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ test_DDLStatements ��� Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ test_BadBinding ��� Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ test_BadParse ��� Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] ������ test_EmptyStatement ��� Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,223 [common.py:153] INFO : [java]
05-24-2021 18:44:20,223 [common.py:153] INFO : [java] Failures (5):
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] JUnit Vintage:TrafficCopTest:test_DisconnectAbort
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] MethodSource [className = 'TrafficCopTest', methodName = 'test_DisconnectAbort', methodParameterTypes = '']
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] => org.junit.ComparisonFailure: expected:<[An I/O error occurred while sending to the backen]d.> but was:<[ERROR: Query faile]d.>
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] org.junit.Assert.assertEquals(Assert.java:115)
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] org.junit.Assert.assertEquals(Assert.java:144)
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] TrafficCopTest.test_DisconnectAbort(TrafficCopTest.java:69)
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] java.base/java.lang.reflect.Method.invoke(Method.java:566)
05-24-2021 18:44:20,224 [common.py:153] INFO : [java] org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] [...]
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] JUnit Vintage:TrafficCopTest:test_DDLStatements
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] MethodSource [className = 'TrafficCopTest', methodName = 'test_DDLStatements', methodParameterTypes = '']
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] => org.postgresql.util.PSQLException: Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:285)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:217)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] org.postgresql.Driver.makeConnection(Driver.java:458)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] org.postgresql.Driver.connect(Driver.java:260)
05-24-2021 18:44:20,225 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:677)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:189)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] TestUtility.makeConnection(TestUtility.java:52)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] TestUtility.makeDefaultConnection(TestUtility.java:27)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] TrafficCopTest.Setup(TrafficCopTest.java:18)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] [...]
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] JUnit Vintage:TrafficCopTest:test_BadBinding
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] MethodSource [className = 'TrafficCopTest', methodName = 'test_BadBinding', methodParameterTypes = '']
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] => org.postgresql.util.PSQLException: Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:285)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:217)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] org.postgresql.Driver.makeConnection(Driver.java:458)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] org.postgresql.Driver.connect(Driver.java:260)
05-24-2021 18:44:20,226 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:677)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:189)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] TestUtility.makeConnection(TestUtility.java:52)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] TestUtility.makeDefaultConnection(TestUtility.java:27)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] TrafficCopTest.Setup(TrafficCopTest.java:18)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] [...]
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] JUnit Vintage:TrafficCopTest:test_BadParse
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] MethodSource [className = 'TrafficCopTest', methodName = 'test_BadParse', methodParameterTypes = '']
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] => org.postgresql.util.PSQLException: Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:285)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:217)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] org.postgresql.Driver.makeConnection(Driver.java:458)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] org.postgresql.Driver.connect(Driver.java:260)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:677)
05-24-2021 18:44:20,227 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:189)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] TestUtility.makeConnection(TestUtility.java:52)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] TestUtility.makeDefaultConnection(TestUtility.java:27)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] TrafficCopTest.Setup(TrafficCopTest.java:18)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] [...]
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] JUnit Vintage:TrafficCopTest:test_EmptyStatement
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] MethodSource [className = 'TrafficCopTest', methodName = 'test_EmptyStatement', methodParameterTypes = '']
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] => org.postgresql.util.PSQLException: Connection to localhost:15721 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:285)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:217)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] org.postgresql.Driver.makeConnection(Driver.java:458)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] org.postgresql.Driver.connect(Driver.java:260)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:677)
05-24-2021 18:44:20,228 [common.py:153] INFO : [java] java.sql/java.sql.DriverManager.getConnection(DriverManager.java:189)
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] TestUtility.makeConnection(TestUtility.java:52)
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] TestUtility.makeDefaultConnection(TestUtility.java:27)
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] TrafficCopTest.Setup(TrafficCopTest.java:18)
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [...]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] Test run finished after 7591 ms
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 4 containers found ]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 0 containers skipped ]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 4 containers started ]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 0 containers aborted ]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 4 containers successful ]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 0 containers failed ]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 6 tests found ]
05-24-2021 18:44:20,229 [common.py:153] INFO : [java] [ 0 tests skipped ]
05-24-2021 18:44:20,230 [common.py:153] INFO : [java] [ 6 tests started ]
05-24-2021 18:44:20,230 [common.py:153] INFO : [java] [ 0 tests aborted ]
05-24-2021 18:44:20,230 [common.py:153] INFO : [java] [ 1 tests successful ]
05-24-2021 18:44:20,230 [common.py:153] INFO : [java] [ 5 tests failed ]
05-24-2021 18:44:20,230 [common.py:153] INFO : [java]
05-24-2021 18:44:20,230 [common.py:153] INFO :
05-24-2021 18:44:20,230 [common.py:153] INFO : BUILD FAILED
05-24-2021 18:44:20,230 [common.py:153] INFO : /jenkins/workspace/terrier_PR-1589/script/testing/junit/build.xml:91: Java returned: 1
05-24-2021 18:44:20,230 [common.py:153] INFO :
05-24-2021 18:44:20,230 [common.py:153] INFO : Total time: 11 seconds
05-24-2021 18:44:20,230 [db_server.py:149] INFO : DBMS already terminated, code: -6
05-24-2021 18:44:20,230 [db_server.py:198] INFO : ************ DB Logs Start ************
05-24-2021 18:44:20,231 [common.py:180] ERROR:
05-24-2021 18:44:20,231 [db_server.py:200] INFO : ************* DB Logs End *************
05-24-2021 18:44:20,232 [test_server.py:151] ERROR: The test suite failed
05-24-2021 18:44:20,232 [__main__.py:51] INFO :
Bug Report
Summary
script.testing.junit failure, no clue why, not reliably reproducing, DBMS appeared to crash (-6) after WireTest/in TrafficCopTest's DisconnectAbortTest. Happened after merging #1553, but I cannot figure out why this would cause an issue (barring extremely cursed interactions with metrics enabled).
Environment
Jenkins/CI: http://jenkins.db.cs.cmu.edu:8080/blue/organizations/jenkins/terrier/detail/master/950/pipeline/
CI log