Expected shutdown/log behaviour during unit tests?

Rainer Jung Fri, 13 Jul 2012 02:58:00 -0700

When comparing output from different unit test runs I observed that thetest result log statement happens sometime betwenn the beginning of theshutdown and the end of the shutdown. It seems non-deterministic whereexactly the log statement happens.

Is this expected? Does anyone know an easy way of normalizing it, e.g.JUnit always logging *after* complete shutdown?


Some Examples

Expected:

[junit] Jul 13, 2012 9:45:52 AM org.apache.coyote.AbstractProtocolpause[junit] INFO: Pausing ProtocolHandler["http-bio-127.0.0.1-auto-1-51108"][junit] Jul 13, 2012 9:45:52 AMorg.apache.catalina.core.StandardService stopInternal

    [junit] INFO: Stopping service Tomcat

[junit] Jul 13, 2012 9:45:52 AMorg.apache.catalina.core.StandardWrapper unload

    [junit] INFO: Waiting for 2 instance(s) to be deallocated

[junit] Jul 13, 2012 9:45:53 AMorg.apache.catalina.core.StandardWrapper unload

    [junit] INFO: Waiting for 2 instance(s) to be deallocated
    [junit] Jul 13, 2012 9:45:53 AM org.apache.coyote.AbstractProtocol stop

[junit] INFO: Stopping ProtocolHandler["http-bio-127.0.0.1-auto-1-51108"][junit] Jul 13, 2012 9:45:53 AM org.apache.coyote.AbstractProtocoldestroy[junit] INFO: Destroying ProtocolHandler["http-bio-127.0.0.1-auto-1-51108"]


Now JUnit result log message after the end of shutdown:

    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 8.573 sec


Observed extreme case:

[junit] Jul 13, 2012 9:43:55 AM org.apache.coyote.AbstractProtocolstart[junit] INFO: Starting ProtocolHandler["http-bio-127.0.0.1-auto-7-51009"]


JUnit result log statement comes very early:

    [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 17.056 sec

Now the shutdown log messages

[junit] Jul 13, 2012 9:44:07 AM org.apache.coyote.AbstractProtocolpause[junit] INFO: Pausing ProtocolHandler["http-bio-127.0.0.1-auto-7-51009"][junit] Jul 13, 2012 9:44:07 AMorg.apache.catalina.core.StandardService stopInternal

    [junit] INFO: Stopping service Tomcat
    [junit] Jul 13, 2012 9:44:07 AM org.apache.coyote.AbstractProtocol stop

[junit] INFO: Stopping ProtocolHandler["http-bio-127.0.0.1-auto-7-51009"][junit] Jul 13, 2012 9:44:07 AM org.apache.coyote.AbstractProtocoldestroy[junit] INFO: Destroying ProtocolHandler["http-bio-127.0.0.1-auto-7-51009"]



Other not so extreme case:

[junit] Jul 13, 2012 9:46:32 AM org.apache.coyote.AbstractProtocolpause[junit] INFO: Pausing ProtocolHandler["http-bio-127.0.0.1-auto-1-51167"][junit] Jul 13, 2012 9:46:32 AMorg.apache.catalina.core.StandardService stopInternal

    [junit] INFO: Stopping service Tomcat
    [junit] Jul 13, 2012 9:46:32 AM org.apache.coyote.AbstractProtocol stop

[junit] INFO: Stopping ProtocolHandler["http-bio-127.0.0.1-auto-1-51167"]


JUnit result message just a bit early:

    [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 4.253 sec

[junit] Jul 13, 2012 9:46:32 AM org.apache.coyote.AbstractProtocoldestroy[junit] INFO: Destroying ProtocolHandler["http-bio-127.0.0.1-auto-1-51167"]



Regards,

Rainer

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org

Expected shutdown/log behaviour during unit tests?

Reply via email to