search

rieckpil / testing-spring-boot-applications-masterclass

🍃 Build Better Spring Boot Applications: A Comprehensive Testing Course to Boost Your Confidence and Productivity.
https://rieckpil.de/testing-spring-boot-applications-masterclass/
MIT License
306 stars 234 forks source link

Issue starting docker-compose in AbstractWebTest #23

Closed pdavie closed 1 year ago

pdavie commented 3 years ago

I am having an issue with Keycloak when starting the web test profile. This is the error log from the Keycloak docker container, there is an apparent problematic line which I have highlighted below (in context):

Added 'keycloak' to '/opt/jboss/keycloak/standalone/configuration/keycloak-add-user.json', restart server to load user
-b 0.0.0.0
=========================================================================
  Using Embedded H2 database
=========================================================================
JAVA_OPTS already set in environment; overriding default settings with values: -Dkeycloak.migration.action=import -Dkeycloak.migration.provider=singleFile -Dkeycloak.migration.file=/tmp/keycloak-dump.json
=========================================================================
  JBoss Bootstrap Environment
  JBOSS_HOME: /opt/jboss/keycloak
  JAVA: java
  JAVA_OPTS:  -server -Dkeycloak.migration.action=import -Dkeycloak.migration.provider=singleFile -Dkeycloak.migration.file=/tmp/keycloak-dump.json  --add-exports=java.base/sun.nio.ch=ALL-UNNAMED --add-exports=jdk.unsupported/sun.misc=ALL-UNNAMED --add-exports=jdk.unsupported/sun.reflect=ALL-UNNAMED
=========================================================================
08:38:31,233 INFO  [org.jboss.modules] (main) JBoss Modules version 1.10.1.Final
08:38:32,807 INFO  [org.jboss.msc] (main) JBoss MSC version 1.4.11.Final
08:38:32,827 INFO  [org.jboss.threads] (main) JBoss Threads version 2.3.3.Final
08:38:33,259 INFO  [org.jboss.as] (MSC service thread 1-1) WFLYSRV0049: Keycloak 11.0.0 (WildFly Core 12.0.3.Final) starting
08:38:33,600 INFO  [org.jboss.vfs] (MSC service thread 1-4) VFS000002: Failed to clean existing content for temp file provider of type temp. Enable DEBUG level log to find what caused this
08:38:36,472 INFO  [org.wildfly.security] (ServerService Thread Pool -- 21) ELY00001: WildFly Elytron version 1.12.1.Final
08:38:37,953 INFO  [org.jboss.as.controller.management-deprecated] (Controller Boot Thread) WFLYCTL0028: Attribute 'security-realm' in the resource at address '/core-service=management/management-interface=http-interface' is deprecated, and may be removed in a future version. See the attribute description in the output of the read-resource-description operation to learn more about the deprecation.
08:38:38,047 INFO  [org.jboss.as.controller.management-deprecated] (ServerService Thread Pool -- 10) WFLYCTL0028: Attribute 'security-realm' in the resource at address '/subsystem=undertow/server=default-server/https-listener=https' is deprecated, and may be removed in a future version. See the attribute description in the output of the read-resource-description operation to learn more about the deprecation.
08:38:38,302 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0039: Creating http management service using socket-binding (management-http)
08:38:38,355 INFO  [org.xnio] (MSC service thread 1-1) XNIO version 3.8.1.Final
08:38:38,366 INFO  [org.xnio.nio] (MSC service thread 1-1) XNIO NIO Implementation Version 3.8.1.Final
08:38:38,430 INFO  [org.jboss.as.clustering.jgroups] (ServerService Thread Pool -- 43) WFLYCLJG0001: Activating JGroups subsystem. JGroups version 4.2.4
08:38:38,447 INFO  [org.wildfly.extension.microprofile.config.smallrye._private] (ServerService Thread Pool -- 48) WFLYCONF0001: Activating WildFly MicroProfile Config Subsystem
08:38:38,468 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 52) WFLYNAM0001: Activating Naming Subsystem
08:38:38,481 INFO  [org.jboss.as.security] (ServerService Thread Pool -- 55) WFLYSEC0002: Activating Security Subsystem
08:38:38,512 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 39) WFLYCLINF0001: Activating Infinispan subsystem.
08:38:38,489 WARN  [org.jboss.as.txn] (ServerService Thread Pool -- 57) WFLYTX0013: The node-identifier attribute on the /subsystem=transactions is set to the default value. This is a danger for environments running multiple servers. Please make sure the attribute value is unique.
08:38:38,532 INFO  [org.jboss.as.naming] (MSC service thread 1-3) WFLYNAM0003: Starting Naming Service
08:38:38,573 INFO  [org.wildfly.extension.microprofile.health.smallrye] (ServerService Thread Pool -- 49) WFLYHEALTH0001: Activating Eclipse MicroProfile Health Subsystem
08:38:38,562 INFO  [org.jboss.as.security] (MSC service thread 1-2) WFLYSEC0001: Current PicketBox version=5.0.3.Final-redhat-00005
08:38:38,560 INFO  [org.jboss.as.connector] (MSC service thread 1-4) WFLYJCA0009: Starting JCA Subsystem (WildFly/IronJacamar 1.4.22.Final)
08:38:38,600 INFO  [org.wildfly.extension.microprofile.metrics.smallrye] (ServerService Thread Pool -- 50) WFLYMETRICS0001: Activating Eclipse MicroProfile Metrics Subsystem
08:38:38,602 INFO  [org.wildfly.extension.io] (ServerService Thread Pool -- 40) WFLYIO001: Worker 'default' has auto-configured to 4 IO threads with 32 max task threads based on your 2 available processors
08:38:38,677 INFO  [org.jboss.as.jaxrs] (ServerService Thread Pool -- 41) WFLYRS0016: RESTEasy version 3.12.1.Final
08:38:38,763 INFO  [org.jboss.remoting] (MSC service thread 1-1) JBoss Remoting version 5.0.18.Final
08:38:38,775 INFO  [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 34) WFLYJCA0004: Deploying JDBC-compliant driver class org.h2.Driver (version 1.4)
08:38:38,900 WARN  [org.wildfly.clustering.web.undertow] (ServerService Thread Pool -- 58) WFLYCLWEBUT0007: No routing provider found for default-server; using legacy provider based on static configuration
08:38:39,012 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0003: Undertow 2.1.3.Final starting
08:38:39,010 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-1) WFLYMAIL0001: Bound mail session [java:jboss/mail/Default]
08:38:39,083 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) WFLYJCA0018: Started Driver service with driver-name = h2
08:38:39,111 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 58) WFLYUT0014: Creating file handler for path '/opt/jboss/keycloak/welcome-content' with options [directory-listing: 'false', follow-symlink: 'false', case-sensitive: 'true', safe-symlink-paths: '[]']
08:38:39,381 INFO  [org.jboss.as.ejb3] (MSC service thread 1-4) WFLYEJB0481: Strict pool slsb-strict-max-pool is using a max instance size of 32 (per class), which is derived from thread worker pool sizing.
08:38:39,381 INFO  [org.jboss.as.ejb3] (MSC service thread 1-2) WFLYEJB0482: Strict pool mdb-strict-max-pool is using a max instance size of 8 (per class), which is derived from the number of CPUs on this host.
08:38:39,555 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0012: Started server default-server.
08:38:39,684 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0006: Undertow AJP listener ajp listening on 0.0.0.0:8009
08:38:39,695 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0018: Host default-host starting
08:38:39,690 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0006: Undertow HTTP listener default listening on 0.0.0.0:8080
08:38:39,732 INFO  [org.jboss.modcluster] (ServerService Thread Pool -- 60) MODCLUSTER000001: Initializing mod_cluster version 1.4.1.Final
08:38:39,764 INFO  [org.jboss.modcluster] (ServerService Thread Pool -- 60) MODCLUSTER000032: Listening to proxy advertisements on /224.0.1.105:23364
08:38:39,942 INFO  [org.jboss.as.ejb3] (MSC service thread 1-3) WFLYEJB0493: EJB subsystem suspension complete
08:38:40,051 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) WFLYJCA0001: Bound data source [java:jboss/datasources/ExampleDS]
08:38:40,055 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-3) WFLYJCA0001: Bound data source [java:jboss/datasources/KeycloakDS]
08:38:40,172 INFO  [org.jboss.as.patching] (MSC service thread 1-3) WFLYPAT0050: Keycloak cumulative patch ID is: base, one-off patches include: none
08:38:40,216 WARN  [org.jboss.as.domain.management.security] (MSC service thread 1-3) WFLYDM0111: Keystore /opt/jboss/keycloak/standalone/configuration/application.keystore not found, it will be auto generated on first use with a self signed certificate for host localhost
08:38:40,255 INFO  [org.jboss.as.server.deployment.scanner] (MSC service thread 1-3) WFLYDS0013: Started FileSystemDeploymentService for directory /opt/jboss/keycloak/standalone/deployments
08:38:40,265 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0027: Starting deployment of "keycloak-server.war" (runtime-name: "keycloak-server.war")
08:38:40,498 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0006: Undertow HTTPS listener https listening on 0.0.0.0:8443
08:38:41,173 WARN  [org.jgroups.protocols.UDP] (ServerService Thread Pool -- 60) JGRP000015: the send buffer of socket ManagedMulticastSocketBinding was set to 1.00MB, but the OS only allocated 212.99KB
08:38:41,173 WARN  [org.jgroups.protocols.UDP] (ServerService Thread Pool -- 60) JGRP000015: the receive buffer of socket ManagedMulticastSocketBinding was set to 20.00MB, but the OS only allocated 212.99KB
08:38:41,174 WARN  [org.jgroups.protocols.UDP] (ServerService Thread Pool -- 60) JGRP000015: the send buffer of socket ManagedMulticastSocketBinding was set to 1.00MB, but the OS only allocated 212.99KB
08:38:41,174 WARN  [org.jgroups.protocols.UDP] (ServerService Thread Pool -- 60) JGRP000015: the receive buffer of socket ManagedMulticastSocketBinding was set to 25.00MB, but the OS only allocated 212.99KB
08:38:44,187 INFO  [org.jgroups.protocols.pbcast.GMS] (ServerService Thread Pool -- 60) 40354a638599: no members discovered after 3007 ms: creating cluster as coordinator
08:38:44,974 INFO  [org.infinispan.PERSISTENCE] (MSC service thread 1-4) ISPN000556: Starting user marshaller 'org.wildfly.clustering.infinispan.marshalling.jboss.JBossMarshaller'
08:38:44,976 INFO  [org.infinispan.PERSISTENCE] (MSC service thread 1-2) ISPN000556: Starting user marshaller 'org.wildfly.clustering.infinispan.marshalling.jboss.JBossMarshaller'
08:38:44,993 INFO  [org.infinispan.PERSISTENCE] (MSC service thread 1-3) ISPN000556: Starting user marshaller 'org.wildfly.clustering.infinispan.marshalling.jboss.JBossMarshaller'
08:38:44,986 INFO  [org.infinispan.PERSISTENCE] (MSC service thread 1-1) ISPN000556: Starting user marshaller 'org.wildfly.clustering.infinispan.marshalling.jboss.JBossMarshaller'
08:38:45,038 INFO  [org.infinispan.CONTAINER] (MSC service thread 1-1) ISPN000128: Infinispan version: Infinispan 'Turia' 10.1.8.Final
08:38:45,276 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-3) ISPN000078: Starting JGroups channel ejb
08:38:45,278 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-4) ISPN000078: Starting JGroups channel ejb
08:38:45,280 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000078: Starting JGroups channel ejb
08:38:45,286 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-1) ISPN000078: Starting JGroups channel ejb
08:38:45,288 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-4) ISPN000094: Received new cluster view for channel ejb: [40354a638599|0] (1) [40354a638599]
08:38:45,289 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-3) ISPN000094: Received new cluster view for channel ejb: [40354a638599|0] (1) [40354a638599]
08:38:45,289 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000094: Received new cluster view for channel ejb: [40354a638599|0] (1) [40354a638599]
08:38:45,291 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-1) ISPN000094: Received new cluster view for channel ejb: [40354a638599|0] (1) [40354a638599]
08:38:45,303 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-4) ISPN000079: Channel ejb local address is 40354a638599, physical addresses are [172.18.0.4:55200]
08:38:45,323 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000079: Channel ejb local address is 40354a638599, physical addresses are [172.18.0.4:55200]
08:38:45,331 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-1) ISPN000079: Channel ejb local address is 40354a638599, physical addresses are [172.18.0.4:55200]
08:38:45,339 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-3) ISPN000079: Channel ejb local address is 40354a638599, physical addresses are [172.18.0.4:55200]
08:38:45,363 INFO  [org.infinispan.PERSISTENCE] (MSC service thread 1-2) ISPN000556: Starting user marshaller 'org.wildfly.clustering.infinispan.marshalling.jboss.JBossMarshaller'
08:38:45,388 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000078: Starting JGroups channel ejb
08:38:45,396 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000094: Received new cluster view for channel ejb: [40354a638599|0] (1) [40354a638599]
08:38:45,418 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000079: Channel ejb local address is 40354a638599, physical addresses are [172.18.0.4:55200]
08:38:45,821 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 61) WFLYCLINF0002: Started client-mappings cache from ejb container
08:38:46,143 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 65) WFLYCLINF0002: Started sessions cache from keycloak container
08:38:46,143 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 61) WFLYCLINF0002: Started actionTokens cache from keycloak container
08:38:46,147 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 62) WFLYCLINF0002: Started offlineSessions cache from keycloak container
08:38:46,149 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 66) WFLYCLINF0002: Started work cache from keycloak container
08:38:46,162 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 63) WFLYCLINF0002: Started clientSessions cache from keycloak container
08:38:46,163 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 68) WFLYCLINF0002: Started loginFailures cache from keycloak container
08:38:46,192 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 67) WFLYCLINF0002: Started offlineClientSessions cache from keycloak container
08:38:46,202 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 60) WFLYCLINF0002: Started authenticationSessions cache from keycloak container
08:38:46,214 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 70) WFLYCLINF0002: Started authorization cache from keycloak container
08:38:46,216 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 69) WFLYCLINF0002: Started keys cache from keycloak container
08:38:46,218 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 71) WFLYCLINF0002: Started realms cache from keycloak container
08:38:46,221 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 64) WFLYCLINF0002: Started users cache from keycloak container
08:38:46,394 WARN  [org.jboss.as.server.deployment] (MSC service thread 1-2) WFLYSRV0273: Excluded subsystem webservices via jboss-deployment-structure.xml does not exist.
08:38:47,232 INFO  [org.keycloak.services] (ServerService Thread Pool -- 64) KC-SERVICES0001: Loading config from standalone.xml or domain.xml
08:38:47,516 INFO  [org.keycloak.url.DefaultHostnameProviderFactory] (ServerService Thread Pool -- 64) Frontend: <request>, Admin: <frontend>, Backend: <request>
08:38:47,972 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 64) WFLYCLINF0002: Started realmRevisions cache from keycloak container
08:38:47,975 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 64) WFLYCLINF0002: Started userRevisions cache from keycloak container
08:38:47,979 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 64) WFLYCLINF0002: Started authorizationRevisions cache from keycloak container
08:38:47,980 INFO  [org.keycloak.connections.infinispan.DefaultInfinispanConnectionProviderFactory] (ServerService Thread Pool -- 64) Node name: 40354a638599, Site name: null
08:38:53,229 INFO  [org.keycloak.connections.jpa.updater.liquibase.LiquibaseJpaUpdaterProvider] (ServerService Thread Pool -- 64) Initializing database schema. Using changelog META-INF/jpa-changelog-master.xml
08:38:55,779 INFO  [org.hibernate.jpa.internal.util.LogHelper] (ServerService Thread Pool -- 64) HHH000204: Processing PersistenceUnitInfo [
    name: keycloak-default
    ...]
08:38:55,909 INFO  [org.hibernate.Version] (ServerService Thread Pool -- 64) HHH000412: Hibernate Core {5.3.17.Final}
08:38:55,911 INFO  [org.hibernate.cfg.Environment] (ServerService Thread Pool -- 64) HHH000206: hibernate.properties not found
08:38:56,223 INFO  [org.hibernate.annotations.common.Version] (ServerService Thread Pool -- 64) HCANN000001: Hibernate Commons Annotations {5.0.5.Final}
08:38:56,659 INFO  [org.hibernate.dialect.Dialect] (ServerService Thread Pool -- 64) HHH000400: Using dialect: org.hibernate.dialect.H2Dialect
08:38:56,668 WARN  [org.hibernate.dialect.H2Dialect] (ServerService Thread Pool -- 64) HHH000431: Unable to determine H2 database version, certain features may not work
08:38:56,722 INFO  [org.hibernate.envers.boot.internal.EnversServiceImpl] (ServerService Thread Pool -- 64) Envers integration enabled? : true
08:38:57,518 INFO  [org.hibernate.orm.beans] (ServerService Thread Pool -- 64) HHH10005002: No explicit CDI BeanManager reference was passed to Hibernate, but CDI is available on the Hibernate ClassLoader.
08:38:57,637 INFO  [org.hibernate.validator.internal.util.Version] (ServerService Thread Pool -- 64) HV000001: Hibernate Validator 6.0.20.Final
08:38:59,371 INFO  [org.hibernate.hql.internal.QueryTranslatorFactoryInitiator] (ServerService Thread Pool -- 64) HHH000397: Using ASTQueryTranslatorFactory
08:39:00,627 INFO  [org.keycloak.services] (ServerService Thread Pool -- 64) KC-SERVICES0030: Full model import requested. Strategy: OVERWRITE_EXISTING
08:39:00,628 INFO  [org.keycloak.exportimport.singlefile.SingleFileImportProvider] (ServerService Thread Pool -- 64) Full importing from file /tmp/keycloak-dump.json
08:39:03,764 INFO  [org.keycloak.exportimport.util.ImportUtils] (ServerService Thread Pool -- 64) Realm 'master' imported
08:39:07,176 INFO  [org.keycloak.exportimport.util.ImportUtils] (ServerService Thread Pool -- 64) Realm 'spring' imported
08:39:07,322 INFO  [org.keycloak.services] (ServerService Thread Pool -- 64) KC-SERVICES0032: Import finished successfully
08:39:07,323 INFO  [org.keycloak.services] (ServerService Thread Pool -- 64) KC-SERVICES0006: Importing users from '/opt/jboss/keycloak/standalone/configuration/keycloak-add-user.json'
08:39:07,470 WARN  [org.keycloak.services] (ServerService Thread Pool -- 64) KC-SERVICES0104: Not creating user keycloak. It already exists.
08:39:07,523 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002225: Deploying javax.ws.rs.core.Application: class org.keycloak.services.resources.KeycloakApplication
08:39:07,527 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002200: Adding class resource org.keycloak.services.resources.JsResource from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,527 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002200: Adding class resource org.keycloak.services.resources.ThemeResource from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,528 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002205: Adding provider class org.keycloak.services.filters.KeycloakSecurityHeadersFilter from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,528 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002205: Adding provider class org.keycloak.services.error.KeycloakErrorHandler from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,529 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002210: Adding provider singleton org.keycloak.services.util.ObjectMapperResolver from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,529 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002220: Adding singleton resource org.keycloak.services.resources.RobotsResource from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,530 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002220: Adding singleton resource org.keycloak.services.resources.RealmsResource from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,537 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002220: Adding singleton resource org.keycloak.services.resources.admin.AdminRoot from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,537 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 64) RESTEASY002220: Adding singleton resource org.keycloak.services.resources.WelcomeResource from Application class org.keycloak.services.resources.KeycloakApplication
08:39:07,684 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 64) WFLYUT0021: Registered web context: '/auth' for server 'default-server'
08:39:07,841 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 46) WFLYSRV0010: Deployed "keycloak-server.war" (runtime-name : "keycloak-server.war")
08:39:07,935 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0212: Resuming server
08:39:07,941 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: Keycloak 11.0.0 (WildFly Core 12.0.3.Final) started in 38105ms - Started 686 of 991 services (703 services are lazy, passive or on-demand)
08:39:07,946 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0060: Http management interface listening on http://127.0.0.1:9990/management
08:39:07,947 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:9990

00:08:39,160 WARN [org.keycloak.events] (default task-4) type=LOGIN_ERROR, realmId=spring, clientId=null, userId=null, ipAddress=172.18.0.1, error=expired_code, restart_after_timeout=true, authSessionParentId=b07fcde2-41a2-4102-a778-24d51d6a44e1, authSessionTabId=iPqoHSnkW1U

04:09:33,052 INFO  [org.jboss.as.server] (Thread-1) WFLYSRV0272: Suspending server
04:09:33,148 INFO  [org.jboss.as.ejb3] (Thread-1) WFLYEJB0493: EJB subsystem suspension complete
04:09:33,177 INFO  [org.jboss.as.server] (Thread-1) WFLYSRV0220: Server shutdown has been requested via an OS signal
04:09:33,532 INFO  [org.infinispan.manager.DefaultCacheManager] (MSC service thread 1-1) Stopping cache manager null on 40354a638599
04:09:33,538 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-2) WFLYJCA0010: Unbound data source [java:jboss/datasources/KeycloakDS]
04:09:33,545 INFO  [org.infinispan.manager.DefaultCacheManager] (MSC service thread 1-2) Stopping cache manager null on 40354a638599
04:09:33,572 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0008: Undertow HTTPS listener https suspending
04:09:33,589 INFO  [org.infinispan.manager.DefaultCacheManager] (MSC service thread 1-4) Stopping cache manager null on 40354a638599
04:09:33,596 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0007: Undertow HTTPS listener https stopped, was bound to 0.0.0.0:8443
04:09:33,605 INFO  [org.jboss.as.mail.extension] (MSC service thread 1-3) WFLYMAIL0002: Unbound mail session [java:jboss/mail/Default]
04:09:33,605 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-4) ISPN000080: Disconnecting JGroups channel ejb
04:09:33,606 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000080: Disconnecting JGroups channel ejb
04:09:33,733 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-1) ISPN000080: Disconnecting JGroups channel ejb
04:09:33,752 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 75) WFLYUT0022: Unregistered web context: '/auth' from server 'default-server'
04:09:33,929 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0008: Undertow AJP listener ajp suspending
04:09:33,932 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0007: Undertow AJP listener ajp stopped, was bound to 0.0.0.0:8009
04:09:33,952 INFO  [org.jboss.modcluster] (ServerService Thread Pool -- 74) MODCLUSTER000002: Initiating mod_cluster shutdown
04:09:33,966 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-1) WFLYJCA0010: Unbound data source [java:jboss/datasources/ExampleDS]
04:09:34,001 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-1) WFLYJCA0019: Stopped Driver service with driver-name = h2
04:09:34,011 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-2) WFLYUT0019: Host default-host stopping
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 64) WFLYCLINF0003: Stopped keys cache from keycloak container
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 85) WFLYCLINF0003: Stopped offlineClientSessions cache from keycloak container
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 83) WFLYCLINF0003: Stopped actionTokens cache from keycloak container
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 74) WFLYCLINF0003: Stopped offlineSessions cache from keycloak container
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 78) WFLYCLINF0003: Stopped loginFailures cache from keycloak container
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 81) WFLYCLINF0003: Stopped sessions cache from keycloak container
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 77) WFLYCLINF0003: Stopped clientSessions cache from keycloak container
04:09:34,113 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 76) WFLYCLINF0003: Stopped authenticationSessions cache from keycloak container
04:09:34,114 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 79) WFLYCLINF0003: Stopped work cache from keycloak container
04:09:34,133 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 84) WFLYCLINF0003: Stopped users cache from keycloak container
04:09:34,136 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 82) WFLYCLINF0003: Stopped authorization cache from keycloak container
04:09:34,166 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 80) WFLYCLINF0003: Stopped realms cache from keycloak container
04:09:34,166 INFO  [org.infinispan.manager.DefaultCacheManager] (MSC service thread 1-2) Stopping cache manager null on 40354a638599
04:09:34,172 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0008: Undertow HTTP listener default suspending
04:09:34,173 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0007: Undertow HTTP listener default stopped, was bound to 0.0.0.0:8080
04:09:34,179 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 75) WFLYCLINF0003: Stopped client-mappings cache from ejb container
04:09:34,192 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-2) ISPN000080: Disconnecting JGroups channel ejb
04:09:34,194 INFO  [org.infinispan.manager.DefaultCacheManager] (MSC service thread 1-1) Stopping cache manager null on 40354a638599
04:09:34,205 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0004: Undertow 2.1.3.Final stopping
04:09:34,216 INFO  [org.infinispan.CLUSTER] (MSC service thread 1-1) ISPN000080: Disconnecting JGroups channel ejb
04:09:34,358 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0028: Stopped deployment keycloak-server.war (runtime-name: keycloak-server.war) in 1042ms
04:09:34,416 INFO  [org.jboss.as] (MSC service thread 1-4) WFLYSRV0050: Keycloak 11.0.0 (WildFly Core 12.0.3.Final) stopped in 1094ms

Any thoughts?

rieckpil commented 3 years ago

Which operating system are you using and what's your Docker + Docker Compose version?

The highlighted WARN seems less critical and I'm wondering why Keycloak stops because of an invalid login attempt.

I assume, every web test (*WT) is therefore currently failing on your side?

pdavie commented 3 years ago

I am using Windows 10 Pro with Docker Desktop. With Docker on Windows, there are two options to run containers, Windows Containers and Windows Subsystem for Linux. Unfortunately, I have had no success with either.

Yes, unfortunately, the testing container stops because Keycloak exits which means that all of the web tests cannot run. The really odd thing is that I can run the Keycloak docker image separately without any difficulty. I guess I could try taking Keycloak out of the docker-compose.yml file and start a separate container for Keycloak and see if this makes any difference... I will try to remember to do this and get back to you with the outcome.

rieckpil commented 3 years ago

@pdavie can you try to run all tests with mvn verify and the recent code? I did add some improvements for Windows and tried it on my Windows machine (aka. it works on my machine).

pdavie commented 3 years ago

I have just updated the code and run mvn verify and am still having issues with docker. I will try it again when I have some spare time. Thank you for your help.

rieckpil commented 1 year ago

Going to close this due to inactivity, please feel free to ping me if the issue persists @pdavie