Skip to content

Instantly share code, notes, and snippets.

View vmassol's full-sized avatar

Vincent Massol vmassol

View GitHub Profile
12:01:18.842 [tc-okhttp-stream-566977253] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2020-06-18 12:01:18,842 [XWiki initialization] DEBUG c.x.x.s.DBCPConnectionProvider - active: [0] (max: [50]), idle: [3] (max: [5])
12:01:18.843 [tc-okhttp-stream-566977253] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2020-06-18 12:01:18,842 [XWiki initialization] DEBUG c.x.x.s.DBCPConnectionProvider - Context of call
12:01:18.843 [tc-okhttp-stream-566977253] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: java.lang.Exception: closeConnection() finished
12:01:18.843 [tc-okhttp-stream-566977253] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: at com.xpn.xwiki.store.DBCPConnectionProvider.closeConnection(DBCPConnectionProvider.java:267)
12:01:18.844 [tc-okhttp-stream-566977253] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: at org.hibernate.internal.NonContextualJdbcConnectionAccess.releaseConnection(NonContextualJdbcConnectionAccess.java:49)
12:01:18.844 [tc-okhttp-str
1) ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: YES)
Logs: https://ci.xwiki.org/job/XWiki/job/xwiki-platform/job/master/3345/testReport/junit/org.xwiki.flamingo.test.ui/FlamingoThemeIT/MariaDB_10_4_x__Jetty_9_x__Java_11___Firefox___Docker_tests_for_xwiki_platform_flamingo_theme___Build_for_MariaDB_10_4_x__Jetty_9_x__Java_11___Firefox___Docker_tests_for_xwiki_platform_flamingo_theme___org_xwiki_flamingo_test_ui_FlamingoThemeIT/
2) Timed out waiting for URL to be accessible (http://172.17.0.1:32784/xwiki/bin/get/Main/WebHome should return HTTP [200])
Logs:
* https://ci.xwiki.org/job/XWiki/job/xwiki-platform/job/master/3345/testReport/junit/org.xwiki.mail.test.ui/MailIT/MariaDB_10_4_x__Jetty_9_x__Java_11___Firefox___Docker_tests_for_xwiki_platform_mail___Build_for_MariaDB_10_4_x__Jetty_9_x__Java_11___Firefox___Docker_tests_for_xwiki_platform_mail___org_xwiki_mail_test_ui_MailIT/
* https://ci.xwiki.org/job/XWiki/job/xwiki-platform/job/master/3345/testReport/junit/org.xwiki.ma
...
01:04:27.115 [main] DEBUG 🐳 [mysql:8.0] - Trying to create JDBC connection using com.mysql.cj.jdbc.Driver to jdbc:mysql://172.17.0.1:43271/xwiki?useSSL=false&allowPublicKeyRetrieval=true with properties: {user=xwiki, password=xwiki}
01:04:27.218 [main] DEBUG 🐳 [mysql:8.0] - Trying to create JDBC connection using com.mysql.cj.jdbc.Driver to jdbc:mysql://172.17.0.1:43271/xwiki?useSSL=false&allowPublicKeyRetrieval=true with properties: {user=xwiki, password=xwiki}
01:04:27.322 [main] DEBUG 🐳 [mysql:8.0] - Failure when trying test query
java.sql.SQLException: Could not create new connection
at org.testcontainers.containers.JdbcDatabaseContainer.createConnection(JdbcDatabaseContainer.java:210)
at org.testcontainers.containers.JdbcDatabaseContainer.waitUntilContainerStarted(JdbcDatabaseContainer.java:129)
at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:441)
at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:325)
at org.rnorth.ducttape.u
May 25 11:03:33 vpsagent-2-dev kernel: [17191123.599885] lowmem_reserve[]: 0 0 4801 4801 4801
May 25 11:03:33 vpsagent-2-dev kernel: [17191123.600999] Node 0 Normal free:41340kB min:41732kB low:52164kB high:62596kB active_anon:1120252kB inactive_anon:82364kB active_file:524kB inactive_file:1552kB unevictable:0kB writepending:0kB present:5046272kB managed:4916372kB mlocked:0kB kernel_stack:3440kB pagetables:6140kB bounce:0kB free_pcp:1316kB local_pcp:848kB free_cma:0kB
May 25 11:03:33 vpsagent-2-dev kernel: [17191123.607172] lowmem_reserve[]: 0 0 0 0 0
May 25 11:03:33 vpsagent-2-dev kernel: [17191123.608133] Node 0 DMA: 1*4kB (U) 0*8kB 0*16kB 1*32kB (U) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15908kB
May 25 11:03:33 vpsagent-2-dev kernel: [17191123.611048] Node 0 DMA32: 2632*4kB (UE) 1250*8kB (UME) 627*16kB (UME) 37*32kB (UME) 57*64kB (UME) 34*128kB (UME) 7*256kB (UME) 0*512kB 1*1024kB (M) 1*2048kB (H) 0*4096kB = 44608kB
May 25 11:03:33 vpsagent-2-dev kernel: [171911
[16819271.160778] Out of memory: Kill process 62915 (java) score 149 or sacrifice child
[16819271.162643] Killed process 63299 (sh) total-vm:4284kB, anon-rss:72kB, file-rss:0kB, shmem-rss:0kB
[16819271.168356] oom_reaper: reaped process 63299 (sh), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
[16819271.469799] timeout-check-t invoked oom-killer: gfp_mask=0x6200ca(GFP_HIGHUSER_MOVABLE), nodemask=(null), order=0, oom_score_adj=0
[16819271.472495] timeout-check-t cpuset=dbd44028d171113fafce90f7f463e34741872b4c009b4745d690822a84f0382e mems_allowed=0
[16819271.474848] CPU: 0 PID: 63296 Comm: timeout-check-t Not tainted 4.19.0-5-cloud-amd64 #1 Debian 4.19.37-5+deb10u2
[16819271.477155] Hardware name: OpenStack Foundation OpenStack Nova, BIOS 2:1.10.2-58953eb7 04/01/2014
[16819271.479204] Call Trace:
[16819271.479935] dump_stack+0x5c/0x80
[16819271.480831] dump_header+0x6b/0x283
{"id":["cleanAuthors"],"state":"FINISHED","progress":{"offset":1.0},"log":{"offset":0,"items":[{"level":"info","renderedMessage":" <div> \n \n Starting job of type [cleanAuthors] with identifier [cleanAuthors]</div>\n "},{"level":"info","renderedMessage":" <div> \n User [<a href=\"/xwiki/bin/view/Main/\">Home</a> &raquo; <a href=\"/xwiki/bin/view/XWiki/\">XWiki</a> &raquo; <a href=\"/xwiki/bin/view/XWiki/test1\">test1</a>] is being removed...</div>\n "},{"level":"info","renderedMessage":" <div> \n User [<a href=\"/xwiki/bin/view/Main/\">Home</a> &raquo; <a href=\"/xwiki/bin/view/XWiki/\">XWiki</a> &raquo; <a href=\"/xwiki/bin/view/XWiki/test1\">test1</a>] has been removed.</div>\n "},{"level":"info","renderedMessage":" <div> \n
10:56:42.724 [main] INFO o.x.t.d.i.j.XWikiDockerExtension - (*) Starting Servlet container [TOMCAT]...
10:56:42.752 [main] INFO o.x.t.d.i.junit5.DockerTestUtils - Pulling image [tomcat:9-jdk8]
10:57:04.275 [main] ERROR 🐳 [tomcat:9-jdk8] - Could not start container
java.lang.RuntimeException: java.net.SocketTimeoutException: timeout
at com.github.dockerjava.okhttp.OkHttpInvocationBuilder.execute(OkHttpInvocationBuilder.java:301)
at com.github.dockerjava.okhttp.OkHttpInvocationBuilder.execute(OkHttpInvocationBuilder.java:271)
at com.github.dockerjava.okhttp.OkHttpInvocationBuilder.put(OkHttpInvocationBuilder.java:248)
at com.github.dockerjava.core.exec.CopyArchiveToContainerCmdExec.execute(CopyArchiveToContainerCmdExec.java:32)
at com.github.dockerjava.core.exec.CopyArchiveToContainerCmdExec.execute(CopyArchiveToContainerCmdExec.java:13)
at com.github.dockerjava.core.exec.AbstrSyncDockerCmdExec.exec(AbstrSyncDockerCmdExec.java:21)
[INFO] -------------------------------------------------------
[INFO] T E S T S
[INFO] -------------------------------------------------------
[INFO] Running org.xwiki.vfs.test.ui.AllIT
03:10:33.717 [ducttape-0] DEBUG o.t.d.DockerClientProviderStrategy - Pinging docker daemon...
03:10:43.720 [main] ERROR o.t.d.EnvironmentAndSystemPropertyClientProviderStrategy - ping failed with configuration Environment variables, system properties and defaults. Resolved dockerHost=unix:///var/run/docker.sock due to org.rnorth.ducttape.TimeoutException: org.rnorth.ducttape.TimeoutException: java.util.concurrent.TimeoutException
org.rnorth.ducttape.TimeoutException: org.rnorth.ducttape.TimeoutException: java.util.concurrent.TimeoutException
at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:56)
at org.testcontainers.dockerclient.DockerClientProviderStrategy.ping(DockerClientProviderStrategy.java:183)
at org.testcontainers.dockerclient.EnvironmentAndSystemPropertyClientPr
Analysis:
- CPU seems ok at 13.6% users
- Memory seems low and it could be the issue. There's only 302MB free and that's probably too low for a tomcat container. Now maybe I don't read it correctly. Could someone help me understand what this means please:
> KiB Mem : 16321056 total, 302596 free, 6854956 used, 9163504 buff/cache
- docker ps shows that when tomcat failed there were already 9 containers started, among which 2 were oracle containers, i.e. very heavy beasts. In addition they're starting at exactly the same time too which could put the machine on its knees.
- the docker events at the end show the tomcat9 container creation and then 2 oracle container creation and their dying (which could be caused either by a lack of resource or by TC stopping them since the tomcat container failed to start).
<h3>Standard Output</h3><pre>
11:42:16.564 [main] DEBUG ?.3.0-se2] - Trying to create JDBC connection using oracle.jdbc.OracleDriver to jdbc:oracle:thin:system/oracle@localhost:32839:xe with properties: {user=system, password=oracle}
11:42:16.693 [main] DEBUG ?.3.0-se2] - Trying to create JDBC connection using oracle.jdbc.OracleDriver to jdbc:oracle:thin:system/oracle@localhost:32839:xe with properties: {user=system, password=oracle}
11:42:16.814 [main] DEBUG ?.3.0-se2] - Trying to create JDBC connection using oracle.jdbc.OracleDriver to jdbc:oracle:thin:system/oracle@localhost:32839:xe with properties: {user=system, password=oracle}
11:42:16.940 [main] DEBUG ?.3.0-se2] - Trying to create JDBC connection using oracle.jdbc.OracleDriver to jdbc:oracle:thin:system/oracle@localhost:32839:xe with properties: {user=system, password=oracle}
11:42:17.061 [main] DEBUG ?.3.0-se2] - Trying to create JDBC connection using oracle.jdbc.OracleDriver to jdbc:oracle:thin:system/oracle@localhost:32839:xe with properties: {user=system, password=oracle}
11:4