peterpilgrim / devoxxuk2013-tdd-javaee7

Test-Driven Development with Java EE 7, Arquillian and Embedded Containers
Other
3 stars 2 forks source link

RestfulBookServiceTest failing with 404 error #1

Open phillashworth opened 11 years ago

phillashworth commented 11 years ago

Can't seem to get the RestfulBookService test working, I get a 404 error. I updated the GF embedded to latest as 4.0-b81 was giving java.lang.IllegalStateException: Error initializing key manager factory (unrecoverable key) but otherwise haven't changed anything else.

runtime 'org.glassfish.main.extras:glassfish-embedded-all:4.0'

09:17:20.885 [DEBUG] [TestEventLogger] 
09:17:20.886 [DEBUG] [TestEventLogger] Gradle Worker 1 STARTED
09:17:20.886 [DEBUG] [TestEventLogger] 
09:17:20.887 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest STARTED
09:17:21.833 [DEBUG] [TestEventLogger] 
09:17:21.833 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest STANDARD_OUT
09:17:21.833 [DEBUG] [TestEventLogger]     Found populator: org.glassfish.kernel.embedded.EmbeddedDomainXml
09:17:22.258 [DEBUG] [TestEventLogger] 
09:17:22.259 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest STANDARD_ERROR
09:17:22.259 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:22 AM org.glassfish.security.services.impl.authorization.AuthorizationServiceImpl initialize
09:17:22.259 [DEBUG] [TestEventLogger]     INFO: Authorization Service has successfully initialized.
09:17:22.341 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:22 AM org.hibernate.validator.internal.util.Version <clinit>
09:17:22.341 [DEBUG] [TestEventLogger]     INFO: HV000001: Hibernate Validator 5.0.0.CR4
09:17:22.941 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:22 AM com.sun.enterprise.v3.services.impl.GrizzlyProxy start
09:17:22.942 [DEBUG] [TestEventLogger]     INFO: Grizzly Framework 2.3.1 started in: 15ms - bound to [/0.0.0.0:8.181]
09:17:22.943 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:22 AM com.sun.enterprise.v3.services.impl.GrizzlyService createNetworkProxy
09:17:22.943 [DEBUG] [TestEventLogger]     INFO: Network listener https-listener on port 0 disabled per domain.xml
09:17:22.955 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:22 AM com.sun.enterprise.v3.admin.adapter.AdminEndpointDecider setGuiContextRoot
09:17:22.955 [DEBUG] [TestEventLogger]     INFO: Admin Console Adapter: context root: /admin
09:17:22.958 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:22 AM com.sun.enterprise.v3.admin.adapter.AdminEndpointDecider setGuiContextRoot
09:17:22.958 [DEBUG] [TestEventLogger]     INFO: Admin Console Adapter: context root: /admin
09:17:22.960 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:22 AM com.sun.enterprise.v3.admin.adapter.AdminEndpointDecider setGuiContextRoot
09:17:22.960 [DEBUG] [TestEventLogger]     INFO: Admin Console Adapter: context root: /admin
09:17:23.411 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.v3.server.AppServerStartup postStartupJob
09:17:23.412 [DEBUG] [TestEventLogger]     INFO: Undefined Product Name - define product and version info in config/branding  0.0.0  (0) startup time : Embedded (1.190ms), startup services(861ms), total(2.051ms)
09:17:23.436 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM org.glassfish.jersey.server.ApplicationHandler initialize
09:17:23.437 [DEBUG] [TestEventLogger]     INFO: Initiating Jersey application, version Jersey: 2.0 2013-05-03 14:50:15...
09:17:23.594 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM org.glassfish.admin.mbeanserver.JMXStartupService$JMXConnectorsStarterThread run
09:17:23.595 [DEBUG] [TestEventLogger]     INFO: JMXStartupService has disabled JMXConnector system
09:17:23.670 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.connectors.jms.util.JmsRaUtil getInstalledMqVersion
09:17:23.670 [DEBUG] [TestEventLogger]     WARNING: RAR7000 : Check for a new version of MQ installation failed : /var/folders/fz/_6zs0k_10_b2vmzx8k69fzc80000gn/T/gfembed1444751396707106126tmp/lib/install/applications/jmsra/../imqjmsra.rar (No such file or directory):/var/folders/fz/_6zs0k_10_b2vmzx8k69fzc80000gn/T/gfembed1444751396707106126tmp/lib/install/applications/jmsra/imqjmsra.rar
09:17:23.976 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.security.SecurityLifecycle <init>
09:17:23.977 [DEBUG] [TestEventLogger]     INFO: security.secmgroff
09:17:23.978 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.security.SecurityLifecycle onInitialization
09:17:23.979 [DEBUG] [TestEventLogger]     INFO: sec.service.startup.enter
09:17:23.980 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.security.PolicyLoader loadPolicy
09:17:23.981 [DEBUG] [TestEventLogger]     INFO: policy.loading
09:17:23.997 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.security.auth.realm.Realm doInstantiate
09:17:23.998 [DEBUG] [TestEventLogger]     INFO: realm.loaded.successfully
09:17:23.999 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.security.auth.realm.Realm doInstantiate
09:17:24.000 [DEBUG] [TestEventLogger]     INFO: realm.loaded.successfully
09:17:24.001 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:23 AM com.sun.enterprise.security.auth.realm.Realm doInstantiate
09:17:24.002 [DEBUG] [TestEventLogger]     INFO: realm.loaded.successfully
09:17:24.005 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:24 AM com.sun.enterprise.security.SecurityLifecycle onInitialization
09:17:24.006 [DEBUG] [TestEventLogger]     INFO: sec.service.startup.exit
09:17:24.411 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:24 AM com.sun.enterprise.web.WebContainer createHttpListener
09:17:24.411 [DEBUG] [TestEventLogger]     INFO: Created HTTP listener http-listener on host/port 0.0.0.0:8181
09:17:24.436 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:24 AM com.sun.enterprise.web.VirtualServer addProbes
09:17:24.436 [DEBUG] [TestEventLogger]     SEVERE: Error adding HttpProbes. NetworkListener https-listeners GrizzlyProxy is NULL
09:17:24.439 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:24 AM com.sun.enterprise.web.WebContainer createHosts
09:17:24.440 [DEBUG] [TestEventLogger]     INFO: Created virtual server server
09:17:24.660 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:24 AM org.apache.catalina.realm.JAASRealm setContainer
09:17:24.660 [DEBUG] [TestEventLogger]     INFO: Setting JAAS app name glassfish-web
09:17:24.661 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:24 AM com.sun.enterprise.web.WebContainer loadSystemDefaultWebModules
09:17:24.662 [DEBUG] [TestEventLogger]     INFO: Virtual server server loaded default web module 
09:17:24.960 [DEBUG] [TestEventLogger]     SLF4J: Class path contains multiple SLF4J bindings.
09:17:24.961 [DEBUG] [TestEventLogger]     SLF4J: Found binding in [jar:file:/Users/phill/.gradle/caches/artifacts-23/filestore/org.glassfish.main.extras/glassfish-embedded-all/4.0/jar/92cd26a43fc9f26a4f91204e11e4be1a3a1feb76/glassfish-embedded-all-4.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
09:17:24.962 [DEBUG] [TestEventLogger]     SLF4J: Found binding in [jar:file:/Users/phill/.gradle/caches/artifacts-23/filestore/org.slf4j/slf4j-simple/1.6.4/jar/6998922e7ac5ab307bd51c233776a67da0031298/slf4j-simple-1.6.4.jar!/org/slf4j/impl/StaticLoggerBinder.class]
09:17:24.962 [DEBUG] [TestEventLogger]     SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
09:17:24.963 [DEBUG] [TestEventLogger]     SLF4J: Actual binding is of type [org.slf4j.impl.JDK14LoggerFactory]
09:17:24.977 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:24 AM org.jboss.weld.bootstrap.WeldBootstrap <clinit>
09:17:24.978 [DEBUG] [TestEventLogger]     INFO: WELD-000900 SNAPSHOT
09:17:25.701 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:25 AM org.jboss.weld.bootstrap.Validator validateCustomBean
09:17:25.702 [DEBUG] [TestEventLogger]     WARNING: WELD-001473 javax.enterprise.inject.spi.Bean implementation org.hibernate.validator.internal.cdi.ValidatorFactoryBean@6eb1f06f declared a normal scope but does not implement javax.enterprise.inject.spi.PassivationCapable. It won't be possible to inject this bean into a bean with passivating scope (@SessionScoped, @ConversationScoped). This can be fixed by assigning the Bean implementation a unique id by implementing the PassivationCapable interface.
09:17:25.703 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:25 AM org.jboss.weld.bootstrap.Validator validateCustomBean
09:17:25.704 [DEBUG] [TestEventLogger]     WARNING: WELD-001473 javax.enterprise.inject.spi.Bean implementation org.hibernate.validator.internal.cdi.ValidatorBean@5798483 declared a normal scope but does not implement javax.enterprise.inject.spi.PassivationCapable. It won't be possible to inject this bean into a bean with passivating scope (@SessionScoped, @ConversationScoped). This can be fixed by assigning the Bean implementation a unique id by implementing the PassivationCapable interface.
09:17:25.801 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:25 AM com.sun.enterprise.web.WebApplication start
09:17:25.802 [DEBUG] [TestEventLogger]     INFO: Loading application [c2d07fd8-ef53-44a7-9e99-316227d7b126] at [/c2d07fd8-ef53-44a7-9e99-316227d7b126]
09:17:25.880 [DEBUG] [TestEventLogger]     mag 15, 2013 9:17:25 AM org.glassfish.deployment.admin.DeployCommand execute
09:17:25.881 [DEBUG] [TestEventLogger]     INFO: c2d07fd8-ef53-44a7-9e99-316227d7b126 was successfully deployed in 2.061 milliseconds.
09:17:25.897 [DEBUG] [TestEventLogger] 
09:17:25.897 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest > shouldRetrieveListOfBooksAsPlainText STARTED
09:17:25.914 [DEBUG] [TestEventLogger] 
09:17:25.915 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest > shouldRetrieveListOfBooksAsPlainText STANDARD_OUT
09:17:25.915 [DEBUG] [TestEventLogger]     uri=http://localhost:8181/c2d07fd8-ef53-44a7-9e99-316227d7b126/great/books
09:17:26.193 [DEBUG] [TestEventLogger] 
09:17:26.193 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest > shouldRetrieveListOfBooksAsPlainText FAILED
09:17:26.194 [DEBUG] [TestEventLogger]     java.lang.AssertionError: expected:<200> but was:<404>
09:17:26.195 [DEBUG] [TestEventLogger]         at org.junit.Assert.fail(Assert.java:88)
09:17:26.195 [DEBUG] [TestEventLogger]         at org.junit.Assert.failNotEquals(Assert.java:743)
09:17:26.195 [DEBUG] [TestEventLogger]         at org.junit.Assert.assertEquals(Assert.java:118)
09:17:26.196 [DEBUG] [TestEventLogger]         at org.junit.Assert.assertEquals(Assert.java:555)
09:17:26.196 [DEBUG] [TestEventLogger]         at org.junit.Assert.assertEquals(Assert.java:542)
09:17:26.196 [DEBUG] [TestEventLogger]         at uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest.shouldRetrieveListOfBooksAsPlainText(RestfulBookServiceTest.java:55)
09:17:26.196 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.197 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.197 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.197 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.198 [DEBUG] [TestEventLogger]         at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
09:17:26.198 [DEBUG] [TestEventLogger]         at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
09:17:26.198 [DEBUG] [TestEventLogger]         at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
09:17:26.198 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian$6$1.invoke(Arquillian.java:270)
09:17:26.199 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.container.test.impl.execution.LocalTestExecuter.execute(LocalTestExecuter.java:60)
09:17:26.199 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.199 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.200 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.200 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.200 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
09:17:26.200 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99)
09:17:26.201 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81)
09:17:26.201 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135)
09:17:26.202 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115)
09:17:26.202 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67)
09:17:26.202 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.container.test.impl.execution.ClientTestExecuter.execute(ClientTestExecuter.java:53)
09:17:26.202 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.203 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.203 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.203 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.204 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
09:17:26.204 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99)
09:17:26.205 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81)
09:17:26.205 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createContext(ContainerEventController.java:142)
09:17:26.205 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.container.test.impl.client.ContainerEventController.createTestContext(ContainerEventController.java:129)
09:17:26.206 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.206 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.206 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.207 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.207 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
09:17:26.207 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)
09:17:26.208 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.test.impl.TestContextHandler.createTestContext(TestContextHandler.java:89)
09:17:26.208 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.208 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.209 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.209 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.209 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
09:17:26.209 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)
09:17:26.210 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.test.impl.TestContextHandler.createClassContext(TestContextHandler.java:75)
09:17:26.210 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.210 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.211 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.211 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.211 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
09:17:26.212 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)
09:17:26.212 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:60)
09:17:26.212 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.213 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.213 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.213 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.214 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
09:17:26.214 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)
09:17:26.214 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135)
09:17:26.214 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.test(EventTestRunnerAdaptor.java:111)
09:17:26.215 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian$6.evaluate(Arquillian.java:263)
09:17:26.215 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian$4.evaluate(Arquillian.java:226)
09:17:26.215 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314)
09:17:26.216 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46)
09:17:26.216 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian$5.evaluate(Arquillian.java:240)
09:17:26.216 [DEBUG] [TestEventLogger]         at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
09:17:26.217 [DEBUG] [TestEventLogger]         at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
09:17:26.217 [DEBUG] [TestEventLogger]         at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
09:17:26.217 [DEBUG] [TestEventLogger]         at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
09:17:26.218 [DEBUG] [TestEventLogger]         at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
09:17:26.218 [DEBUG] [TestEventLogger]         at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
09:17:26.219 [DEBUG] [TestEventLogger]         at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
09:17:26.219 [DEBUG] [TestEventLogger]         at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
09:17:26.219 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian$2.evaluate(Arquillian.java:185)
09:17:26.220 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian.multiExecute(Arquillian.java:314)
09:17:26.220 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian.access$100(Arquillian.java:46)
09:17:26.220 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian$3.evaluate(Arquillian.java:199)
09:17:26.221 [DEBUG] [TestEventLogger]         at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
09:17:26.221 [DEBUG] [TestEventLogger]         at org.jboss.arquillian.junit.Arquillian.run(Arquillian.java:147)
09:17:26.221 [DEBUG] [TestEventLogger]         at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:55)
09:17:26.222 [DEBUG] [TestEventLogger]         at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:42)
09:17:26.222 [DEBUG] [TestEventLogger]         at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:71)
09:17:26.222 [DEBUG] [TestEventLogger]         at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:49)
09:17:26.223 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.223 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.223 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.224 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.224 [DEBUG] [TestEventLogger]         at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
09:17:26.224 [DEBUG] [TestEventLogger]         at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
09:17:26.225 [DEBUG] [TestEventLogger]         at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
09:17:26.225 [DEBUG] [TestEventLogger]         at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
09:17:26.225 [DEBUG] [TestEventLogger]         at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
09:17:26.226 [DEBUG] [TestEventLogger]         at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:103)
09:17:26.226 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
09:17:26.226 [DEBUG] [TestEventLogger]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
09:17:26.227 [DEBUG] [TestEventLogger]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
09:17:26.227 [DEBUG] [TestEventLogger]         at java.lang.reflect.Method.invoke(Method.java:601)
09:17:26.227 [DEBUG] [TestEventLogger]         at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
09:17:26.228 [DEBUG] [TestEventLogger]         at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
09:17:26.228 [DEBUG] [TestEventLogger]         at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:355)
09:17:26.228 [DEBUG] [TestEventLogger]         at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:66)
09:17:26.229 [DEBUG] [TestEventLogger]         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
09:17:26.229 [DEBUG] [TestEventLogger]         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
09:17:26.229 [DEBUG] [TestEventLogger]         at java.lang.Thread.run(Thread.java:722)
09:17:26.262 [DEBUG] [TestEventLogger] 
09:17:26.263 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest STANDARD_OUT
09:17:26.263 [DEBUG] [TestEventLogger]     response=ScopedJaxrsResponse{ClientResponse{method=GET, uri=http://localhost:8181/c2d07fd8-ef53-44a7-9e99-316227d7b126/great/books, status=404, reason=Not Found}}PlainTextActionReporterSUCCESSNo monitoring data to report.
09:17:26.266 [QUIET] [system.out] 09:17:26.266 [INFO] [org.gradle.api.internal.tasks.testing.worker.TestWorker] Gradle Worker 1 finished executing tests.
09:17:26.267 [DEBUG] [TestEventLogger] 
09:17:26.267 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest FAILED
09:17:26.268 [DEBUG] [TestEventLogger] 
09:17:26.268 [DEBUG] [TestEventLogger] Gradle Worker 1 FAILED
09:17:26.270 [QUIET] [system.out] 09:17:26.270 [DEBUG] [org.gradle.process.internal.child.ActionExecutionWorker] Completed Gradle Worker 1.
09:17:26.273 [QUIET] [system.out] 09:17:26.273 [DEBUG] [org.gradle.process.internal.child.ActionExecutionWorker] Stopping client connection.
09:17:26.631 [DEBUG] [org.gradle.process.internal.DefaultExecHandle] Changing state to: SUCCEEDED
09:17:26.631 [INFO] [org.gradle.process.internal.DefaultExecHandle] Process 'Gradle Worker 1' finished with exit value 0 (state: SUCCEEDED)
09:17:26.633 [DEBUG] [TestEventLogger] 
09:17:26.633 [DEBUG] [TestEventLogger] Test Run FAILED
09:17:26.635 [ERROR] [org.gradle.api.internal.tasks.testing.logging.TestCountLogger] 
1 test completed, 1 failed
09:17:26.639 [INFO] [org.gradle.api.internal.tasks.testing.junit.result.Binary2JUnitXmlReportGenerator] Finished generating test XML results (0.003 secs)
09:17:26.640 [INFO] [org.gradle.api.internal.tasks.testing.junit.report.DefaultTestReport] Generating HTML test report...
09:17:26.645 [INFO] [org.gradle.api.internal.tasks.testing.junit.report.DefaultTestReport] Finished generating test html results (0.005 secs)
09:17:26.646 [DEBUG] [org.gradle.logging.internal.DefaultLoggingConfigurer] Finished configuring with level: DEBUG, configurers: [org.gradle.logging.internal.OutputEventRenderer@2b46950c, org.gradle.logging.internal.logback.LogbackLoggingConfigurer@26e35d06, org.gradle.logging.internal.JavaUtilLoggingConfigurer@18f048dc]
09:17:26.647 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire exclusive lock on task artifact state cache (/Users/phill/Documents/GitRepo/devoxxuk2013-tdd-javaee7/tdd_je7_arq/.gradle/1.5/taskArtifacts).
09:17:26.647 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Lock acquired.
09:17:26.648 [DEBUG] [org.gradle.api.internal.tasks.execution.ExecuteAtMostOnceTaskExecuter] Finished executing task ':test'
09:17:26.648 [LIFECYCLE] [org.gradle.TaskExecutionLogger] :test FAILED
peterpilgrim commented 11 years ago

Try downgrading from GlassFish 4.0 b81 to b77 - There is an issue with GlassFish missing a library JSON-P that is still not fixed. If you do this you have to change the code to the older JAX-RS 2.0 milestone API, particularly the RemoteEndpoint handlers.

phillashworth commented 11 years ago

I tried that but the container won't start SEVERE: Unable to determine location of server.log file.

Which version of GF embedded did you get the original code working with?

13:10:48.275 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest STANDARD_ERROR
13:10:48.276 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM org.glassfish.security.services.impl.authorization.AuthorizationServiceImpl initialize
13:10:48.276 [DEBUG] [TestEventLogger]     INFO: Authorization Service has successfully initialized.
13:10:48.353 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM org.hibernate.validator.internal.util.Version <clinit>
13:10:48.353 [DEBUG] [TestEventLogger]     INFO: HV000001: Hibernate Validator 5.0.0.CR4
13:10:48.672 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM com.sun.enterprise.config.modularity.StartupConfigBeanOverrider postConstruct
13:10:48.672 [DEBUG] [TestEventLogger]     INFO: Starting the config overriding procedure
13:10:48.818 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM com.sun.enterprise.config.modularity.StartupConfigBeanOverrider postConstruct
13:10:48.818 [DEBUG] [TestEventLogger]     INFO: Overriding Config specified by: org.glassfish.concurrent.config.ManagedThreadFactory
13:10:48.916 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM com.sun.enterprise.config.modularity.StartupConfigBeanOverrider postConstruct
13:10:48.916 [DEBUG] [TestEventLogger]     INFO: Overriding Config specified by: org.glassfish.concurrent.config.ManagedExecutorService
13:10:48.941 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM com.sun.enterprise.config.modularity.StartupConfigBeanOverrider postConstruct
13:10:48.942 [DEBUG] [TestEventLogger]     INFO: Overriding Config specified by: org.glassfish.concurrent.config.ManagedScheduledExecutorService
13:10:48.961 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM com.sun.enterprise.config.modularity.StartupConfigBeanOverrider postConstruct
13:10:48.962 [DEBUG] [TestEventLogger]     INFO: Overriding Config specified by: org.glassfish.concurrent.config.ContextService
13:10:48.985 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:48 PM com.sun.enterprise.config.modularity.StartupConfigBeanOverrider postConstruct
13:10:48.986 [DEBUG] [TestEventLogger]     INFO: Finished the config overriding procedure
13:10:49.241 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM com.sun.enterprise.v3.services.impl.GrizzlyProxy start
13:10:49.242 [DEBUG] [TestEventLogger]     INFO: Grizzly Framework 2.3 started in: 15ms - bound to [/0.0.0.0:8.181]
13:10:49.242 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM com.sun.enterprise.v3.services.impl.GrizzlyService createNetworkProxy
13:10:49.243 [DEBUG] [TestEventLogger]     INFO: Network listener https-listener on port 0 disabled per domain.xml
13:10:49.253 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM com.sun.enterprise.v3.admin.adapter.AdminEndpointDecider setGuiContextRoot
13:10:49.254 [DEBUG] [TestEventLogger]     INFO: Admin Console Adapter: context root: /admin
13:10:49.257 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM com.sun.enterprise.v3.admin.adapter.AdminEndpointDecider setGuiContextRoot
13:10:49.257 [DEBUG] [TestEventLogger]     INFO: Admin Console Adapter: context root: /admin
13:10:49.260 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM com.sun.enterprise.v3.admin.adapter.AdminEndpointDecider setGuiContextRoot
13:10:49.260 [DEBUG] [TestEventLogger]     INFO: Admin Console Adapter: context root: /admin
13:10:49.537 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM com.sun.enterprise.v3.server.AppServerStartup$StartupActivator awaitCompletion
13:10:49.538 [DEBUG] [TestEventLogger]     INFO: Undefined Product Name - define product and version info in config/branding  0.0.0  (0) startup time : Embedded (1.024ms), startup services(988ms), total(2.012ms)
13:10:49.649 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM org.glassfish.jersey.server.ApplicationHandler initialize
13:10:49.650 [DEBUG] [TestEventLogger]     INFO: Initiating Jersey application, version Jersey: 2.0-m12-1 2013-02-15 10:05:31...
13:10:49.667 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM org.glassfish.admin.mbeanserver.JMXStartupService$JMXConnectorsStarterThread run
13:10:49.668 [DEBUG] [TestEventLogger]     INFO: JMXStartupService has disabled JMXConnector system
13:10:49.745 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:49 PM com.sun.enterprise.connectors.jms.util.JmsRaUtil getInstalledMqVersion
13:10:49.746 [DEBUG] [TestEventLogger]     WARNING: RAR7000 : Check for a new version of MQ installation failed : /var/folders/7k/qw8629l12z73tydyj19v8l3c0000gn/T/gfembed5173849559744909556tmp/lib/install/applications/jmsra/../imqjmsra.rar (No such file or directory):/var/folders/7k/qw8629l12z73tydyj19v8l3c0000gn/T/gfembed5173849559744909556tmp/lib/install/applications/jmsra/imqjmsra.rar
13:10:49.782 [DEBUG] [TestEventLogger] 
13:10:49.782 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest STANDARD_OUT
13:10:49.783 [DEBUG] [TestEventLogger]     BatchSniffer instantiated...
13:10:50.121 [DEBUG] [TestEventLogger] 
13:10:50.122 [DEBUG] [TestEventLogger] uk.co.xenonique.devoxxuk13.demo.RestfulBookServiceTest STANDARD_ERROR
13:10:50.122 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.security.SecurityLifecycle <init>
13:10:50.123 [DEBUG] [TestEventLogger]     INFO: security.secmgroff
13:10:50.123 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.security.SecurityLifecycle onInitialization
13:10:50.124 [DEBUG] [TestEventLogger]     INFO: sec.service.startup.enter
13:10:50.127 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.security.PolicyLoader loadPolicy
13:10:50.128 [DEBUG] [TestEventLogger]     INFO: policy.loading
13:10:50.144 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.security.auth.realm.Realm doInstantiate
13:10:50.144 [DEBUG] [TestEventLogger]     INFO: realm.loaded.successfully
13:10:50.145 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.security.auth.realm.Realm doInstantiate
13:10:50.146 [DEBUG] [TestEventLogger]     INFO: realm.loaded.successfully
13:10:50.147 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.security.auth.realm.Realm doInstantiate
13:10:50.147 [DEBUG] [TestEventLogger]     INFO: realm.loaded.successfully
13:10:50.152 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.security.SecurityLifecycle onInitialization
13:10:50.153 [DEBUG] [TestEventLogger]     INFO: sec.service.startup.exit
13:10:50.154 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM ContainerStarter startContainer
13:10:50.155 [DEBUG] [TestEventLogger]     INFO: Snifer com.sun.enterprise.security.ee.SecuritySniffer@389278a3 set up following modules: null
13:10:50.167 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM ContainerStarter startContainer
13:10:50.167 [DEBUG] [TestEventLogger]     INFO: Snifer org.glassfish.web.sniffer.WebSniffer@1ccb7 set up following modules: [com.sun.enterprise.module.single.ProxyModule@181cbbe6, com.sun.enterprise.module.single.ProxyModule@181cbbe6, com.sun.enterprise.module.single.ProxyModule@181cbbe6]
13:10:50.428 [DEBUG] [TestEventLogger]     mag 15, 2013 1:10:50 PM com.sun.enterprise.web.WebContainer postConstruct
13:10:50.428 [DEBUG] [TestEventLogger]     SEVERE: Unable to determine location of server.log file
13:10:50.429 [DEBUG] [TestEventLogger]     java.io.FileNotFoundException: /var/folders/7k/qw8629l12z73tydyj19v8l3c0000gn/T/gfembed5173849559744909556tmp/config/default-logging.properties (No such file or directory)
13:10:50.430 [DEBUG] [TestEventLogger]      at java.io.FileInputStream.open(Native Method)
13:10:50.431 [DEBUG] [TestEventLogger]      at java.io.FileInputStream.<init>(FileInputStream.java:138)
13:10:50.432 [DEBUG] [TestEventLogger]      at com.sun.common.util.logging.LoggingConfigImpl.getDefaultLoggingPropertiesInputStream(LoggingConfigImpl.java:168)
13:10:50.433 [DEBUG] [TestEventLogger]      at com.sun.common.util.logging.LoggingConfigImpl.loadLoggingProperties(LoggingConfigImpl.java:120)
13:10:50.433 [DEBUG] [TestEventLogger]      at com.sun.common.util.logging.LoggingConfigImpl.getLoggingProperties(LoggingConfigImpl.java:374)
13:10:50.434 [DEBUG] [TestEventLogger]      at com.sun.enterprise.web.WebContainer.postConstruct(WebContainer.java:741)
peterpilgrim commented 11 years ago

Glassfish Embedded Server b77 or earlier I think try b72

For a downgrade, You have to change the code in the getRemoteEndpoint(). It was two different inner class name RemoteEndpoint.Basic and RemoteEndpoint.Whole or something like that.

I committed a change for the SSLContext set up in the unit test to solve the security issue. Otherwise wait until they release b88 or b89.

phillashworth commented 11 years ago

Thanks Peter, I think I'll just give up for now and wait for new builds. I've tried b72, b77 and various other builds all with different errors (after downgrading code to reflect API at time of build).

There is a '4.0' build under the promoted builds which is newer than b87 and does seem to contain the JSON-P libraries but gives me the errors initially reported. https://maven.java.net/content/groups/promoted/org/glassfish/main/extras/glassfish-embedded-all/4.0/