kaleidos/grails-postgresql-extensions

postgresql-extensions 4.6.3: domain classes cannot be used in BootStrap.groovy any more

make opened this issue · 19 comments

make commented

After upgrading from 4.6.1 to 4.6.3 domain classes have not been able to be used in BootStrap.groovy any more.

My grails-app/init/BootStrap.groovy:

class BootStrap {

    def init = { servletContext ->
        JobStatus.withNewSession { session ->
            def statuses = JobStatus.findAll{ running == true }
            statuses*.setRunning(false)
            statuses*.save(flush:true)
            if(statuses)
                log.info "Cleared job statuses"
        }
    }
    def destroy = {
    }
}

grails run-app works fine but when deploying war into tomcat there's an error:

2015-12-15 14:06:48,414 [localhost-startStop-1] ERROR grails.boot.GrailsApp - Application startup failed
java.lang.IllegalStateException: Method on class [my.app.JobStatus] was used outside of a Grails application. If running in the context of a test using the mocking API or bootstrap Grails correctly.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_66]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_66]
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_66]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:422) ~[na:1.8.0_66]
        at org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:80) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.reflection.CachedConstructor.doConstructorInvoke(CachedConstructor.java:74) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.ConstructorSite$ConstructorSiteNoUnwrap.callConstructor(ConstructorSite.java:84) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:60) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:235) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:247) ~[groovy-2.4.5.jar:2.4.5]
        at org.grails.datastore.gorm.GormEntity$Trait$Helper.currentGormStaticApi(GormEntity.groovy:69) ~[grails-datastore-gorm-4.0.7.RELEASE.jar:na]
        at org.grails.datastore.gorm.GormEntity$Trait$Helper$currentGormStaticApi$0.call(Unknown Source) ~[na:na]
        at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:125) ~[groovy-2.4.5.jar:2.4.5]
        at my.app.JobStatus.currentGormStaticApi(JobStatus.groovy) ~[JobStatus.class:na]
        at my.app.JobStatus$currentGormStaticApi$0.call(Unknown Source) ~[na:na]
        at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:117) ~[groovy-2.4.5.jar:2.4.5]
        at org.grails.datastore.gorm.GormEntity$Trait$Helper.withNewSession(GormEntity.groovy:810) ~[grails-datastore-gorm-4.0.7.RELEASE.jar:na]
        at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession.call(Unknown Source) ~[na:na]
        at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:133) ~[groovy-2.4.5.jar:2.4.5]
        at my.app.JobStatus.withNewSession(JobStatus.groovy) ~[JobStatus.class:na]
        at my.app.JobStatus$withNewSession.call(Unknown Source) ~[na:na]
        at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113) ~[groovy-2.4.5.jar:2.4.5]
        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:125) ~[groovy-2.4.5.jar:2.4.5]
        at BootStrap$_closure1.doCall(BootStrap.groovy:6) ~[BootStrap$_closure1.class:na]

My dependencies:
grails 3.0.10
org.grails.plugins:postgresql-extensions:4.6.3
org.postgresql:postgresql:9.4-1201-jdbc41

Could you please create a very simple app that reproduces the problem? I would like to see the domain classes to figure it out what happen with the new version. I assume that you're using json or jsonb support, but I'm not sure.

In the mean time, could you please test with the version 4.6.2?

make commented

I was not able to reproduce the problem with 4.6.2 though I was even able to deploy few times with 4.6.3 without problems. See https://github.com/make/postgresql-extensions-issue82

make commented

Somehow when I tried with 4.6.2 without problems and then tried 4.6.3 again the init part in BootStrap.groovy was executed three times???

16-Dec-2015 21:02:24.269 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.29
16-Dec-2015 21:02:24.283 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive /opt/apache-tomcat-8.0.29/webapps/postgresql-extensions-issue82.war
16-Dec-2015 21:02:26.629 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
2015-12-16 21:02:28,060 [localhost-startStop-1] INFO p.e.issue82.ApplicationLoader - Starting ApplicationLoader on markus-Precision-M4800 with PID 1237 (/opt/apache-tomcat-8.0.29/webapps/postgresql-extensions-issue82/WEB-INF/classes started by tomcat in /)
2015-12-16 21:02:35,474 [localhost-startStop-1] INFO grails.app.init.BootStrap - Checking job statuses
2015-12-16 21:02:35,575 [localhost-startStop-1] INFO grails.app.init.BootStrap - All job statuses are OK
2015-12-16 21:02:35,604 [localhost-startStop-1] INFO p.e.issue82.ApplicationLoader - Started ApplicationLoader in 7.955 seconds (JVM running for 11.75)
2015-12-16 21:02:37,204 [localhost-startStop-1] INFO grails.app.init.BootStrap - Checking job statuses
2015-12-16 21:02:37,208 [localhost-startStop-1] INFO grails.app.init.BootStrap - All job statuses are OK
2015-12-16 21:02:37,226 [localhost-startStop-1] INFO grails.app.init.BootStrap - Checking job statuses
2015-12-16 21:02:37,228 [localhost-startStop-1] INFO grails.app.init.BootStrap - All job statuses are OK
16-Dec-2015 21:02:37.272 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive /opt/apache-tomcat-8.0.29/webapps/postgresql-extensions-issue82.war has finished in 12,988 ms
16-Dec-2015 21:02:37.275 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
16-Dec-2015 21:02:37.279 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
16-Dec-2015 21:02:37.280 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 13023 ms

Thank. I'll take a look and tell you something.

First of all thank you. This is the best issue ever. Your example project is great with all the steps to reproduce the issue.

I can't believe this is happening but you're absolutely right. It seems that with 4.6.3 there's some problem. I saw the error you mention and also the three messages during the bootstrap.

I've deployed two different versions of the app. The first time with 4.6.3 and the second one using 4.6.2 and it seems that the dependencies are not the same:

4.6.2:
4 6 2

4.6.3:
4 6 3

If you take a closer look you'll see that with version 4.6.3 the number of domains is 0 but with 4.6.2 is 1. You can also see that the only thing that changes between them is the version of the plugin.

You can see here 6da48e0...b0e56d5 the changes between 4.6.2 and 4.6.3. I only added two new jsonb criterias and I can't imagine how those changes can affect like this. If you have some suggestions I'm all ears...

That is where the sql is built.

The op is the sql operator that is defined here and here. In that code is where I add dynamically the new criterias to the HibernateCriteriaBuilder. In both operators I'm using the same class PgJsonbOperator to add the different sql operators.

The ? will be replaced by the value when the sql is executed.

Is more clear now? I don't know if I've explained very well, so if you have more questions, please ask :)

make commented

I would suggest to add spaces before and after the operators to at least improve debugging. It's hard to read logged queries when query is something like my_jsonb@>? (compare to my_jsonb @> ?). There are also PostgreSQL operators ?, ?| and ?&. But maybe that's worth an another issue :)

You're right, I'll add those spaces to be able to read the queries better.

Regarding the others operators, I only implemented those two because I think they are the most used. But yes, I can add the others or accept a pull-request with the changes ;-)

make commented

I cannot reproduce the issue with locally installed grails plugin. I diffed the local and remote jar contents. The main difference is that remote jar has ApplicationLoader.class in grails/postgresql/extensions folder while the local one doesn't have. Is the public remote jar somehow broken?

make commented

In remote jar there are also UrlMappings.groovy, error.gsp, messages.properties, empty hibernate directory and empty layouts directory that are missing from locally compiled jar.

make commented

File grails/postgresql/extensions/Application.class also differs in local and remote jars

Maybe the file ApplicationLoader.class is the reason why the 4.6.3 version is not working properly.

Regarding UrlMappings.groovy, errors.gsp and messages.properties they are included in the previous versions. Maybe I need to exclude them:

jar {
    exclude 'UrlMappings.groovy'
    exclude 'error.gsp'
    exclude 'messages.properties'
}

I've published to mavenLocal the 4.6.3 version and the ApplicationLoader.class is not included, so maybe the jar published on bintray is broken.

I think I'm going to publish the version 4.6.3 again on bintray and see what happens.

I've just published the version 4.6.4

I've tried several times with the new version and I can't reproduce the issue anymore. The log messages are displayed only once and the "number of Domains" with version 4.6.4 is always 1.

I'm closing the issue. If you have more problems, please comment here or open a new one.

Thank you very much for your help :)

make commented

I confirm that this issue is solved with 4.6.4. Thanks for the fast response!

Happy to help :-)