Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SVT: Application keeps on restarting in Dev mode without making any changes to the app #1755

Open
rumanaHaque opened this issue Nov 9, 2023 · 25 comments
Assignees

Comments

@rumanaHaque
Copy link

I have the ACME application - that I imported in my workspace and start using the Start menu of the Liberty Dashboard.
After starting the application - I see that the app was started, but it keeps on restarting and updating, even though I do not make any changes to my application or the configuration.
c:\eclipse-workspace\acme-ee10\acme-ee\AcmeWebEjbEar>mvn liberty:dev

I get some of the following output:

[INFO] [AUDIT   ] CWWKF0012I: The server installed the following features: [appClientSupport-2.0, appSecurity-5.0, cdi-4.0, connectors-2.1, distributedMap-1.0, enterpriseBeans-4.0, enterpriseBeansHome-4.0, enterpriseBeansLite-4.0, enterpriseBeansPersistentTimer-4.0, enterpriseBeansRemote-4.0, expressionLanguage-5.0, federatedRegistry-1.0, jdbc-4.2, jndi-1.0, json-1.0, jsonb-3.0, jsonp-2.1, jwt-1.0, ldapRegistry-3.0, localConnector-1.0, mdb-4.0, messaging-3.1, messagingClient-3.0, messagingSecurity-3.0, messagingServer-3.0, microProfile-6.0, monitor-1.0, mpConfig-3.0, mpFaultTolerance-4.0, mpHealth-4.0, mpJwt-2.1, mpMetrics-5.0, mpOpenAPI-3.1, mpRestClient-3.0, mpTelemetry-1.0, pages-3.1, persistence-3.1, persistenceContainer-3.1, restfulWS-3.1, restfulWSClient-3.1, servlet-6.0, ssl-1.0, transportSecurity-1.0, xmlBinding-4.0, xmlWS-4.0].
[INFO] [AUDIT   ] CWWKF0011I: The defaultServer server is ready to run a smarter planet. The defaultServer server started in 57.247 seconds.
[INFO] CWWKM2015I: Match number: 1 is [11/9/23, 14:18:25:609 PST] 00000034 com.ibm.ws.kernel.feature.internal.FeatureManager            A CWWKF0011I: The defaultServer server is ready to run a smarter planet. The defaultServer server started in 57.247 seconds..
[INFO] ************************************************************************
[INFO] *    Liberty is running in dev mode.
[INFO] *        Automatic generation of features: [ Off ]
[INFO] *        h - see the help menu for available actions, type 'h' and press Enter.
[INFO] *        q - stop the server and quit dev mode, press Ctrl-C or type 'q' and press Enter.
[INFO] *
[INFO] *    Liberty server port information:
[INFO] *        Liberty server HTTP port: [ 9080 ]
[INFO] *        Liberty debug port: [ 7777 ]
[INFO] ************************************************************************

[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS_CDI/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityPojoWSes/
[INFO] [AUDIT   ] CWWKZ0001I: Application AcmeWebEjbEar started in 64.139 seconds.
[INFO] [WARNING ] Settings: Could not parse struts.locale setting, substituting default VM locale

However, if I use the Liberty Tools to do the same thing - I see that the app doesn't start, and immediately, and it keeps on restarting

[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/ibm/api/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/jwt/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/health/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/metrics/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/openapi/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/openapi/ui/
[INFO] [AUDIT   ] CWWKZ0022W: Application AcmeWebEjbEar has not started in 30.002 seconds.
[INFO] [AUDIT   ] CWWKF0012I: The server installed the following features: [appClientSupport-2.0, appSecurity-5.0, cdi-4.0, connectors-2.1, distributedMap-1.0, enterpriseBeans-4.0, enterpriseBeansHome-4.0, enterpriseBeansLite-4.0, enterpriseBeansPersistentTimer-4.0, enterpriseBeansRemote-4.0, expressionLanguage-5.0, federatedRegistry-1.0, jdbc-4.2, jndi-1.0, json-1.0, jsonb-3.0, jsonp-2.1, jwt-1.0, ldapRegistry-3.0, localConnector-1.0, mdb-4.0, messaging-3.1, messagingClient-3.0, messagingSecurity-3.0, messagingServer-3.0, microProfile-6.0, monitor-1.0, mpConfig-3.0, mpFaultTolerance-4.0, mpHealth-4.0, mpJwt-2.1, mpMetrics-5.0, mpOpenAPI-3.1, mpRestClient-3.0, mpTelemetry-1.0, pages-3.1, persistence-3.1, persistenceContainer-3.1, restfulWS-3.1, restfulWSClient-3.1, servlet-6.0, ssl-1.0, transportSecurity-1.0, xmlBinding-4.0, xmlWS-4.0].
[INFO] [AUDIT   ] CWWKF0011I: The defaultServer server is ready to run a smarter planet. The defaultServer server started in 48.562 seconds.
[INFO] CWWKM2015I: Match number: 1 is [11/9/23, 14:25:13:565 PST] 0000002a com.ibm.ws.kernel.feature.internal.FeatureManager            A CWWKF0011I: The defaultServer server is ready to run a smarter planet. The defaultServer server started in 48.562 seconds..
[INFO] ************************************************************************
[INFO] *    Liberty is running in dev mode.
[INFO] *        Automatic generation of features: [ Off ]
[INFO] *        h - see the help menu for available actions, type 'h' and press Enter.
[INFO] *        q - stop the server and quit dev mode, press Ctrl-C or type 'q' and press Enter.
[INFO] *
[INFO] *    Liberty server port information:
[INFO] *        Liberty server HTTP port: [ 9080 ]
[INFO] *        Liberty server HTTPS port: [ 9443 ]
[INFO] *        Liberty debug port: [ 7777 ]
[INFO] ************************************************************************
.
.
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS_CDI/
[INFO] Running unit tests for acme-ee10 ...
Downloading from sonatype-nexus-snapshots: https://oss.sonatype.org/content/repositories/snapshots/org/apache/maven/plugins/maven-surefire-plugin/maven-metadata.xml
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityPojoWSes/
[INFO] No tests to run.
[INFO] [WARNING ] Settings: Could not parse struts.locale setting, substituting default VM locale
[INFO] Rendering content with org.apache.maven.skins:maven-default-skin:jar:1.3 skin.
[INFO] Unit tests for acme-ee10 finished.
[INFO]
[INFO] Waiting up to 30 seconds to find the application start up or update message...
[INFO] CWWKM2010I: Searching for (CWWKZ0001I:|CWWKZ0003I:) in C:\eclipse-workspace\acme-ee10\acme-ee\AcmeWebEjbEar\target\liberty\wlp\usr\servers\defaultServer\logs\messages.log. This search will timeout after 30 seconds.
[INFO] [AUDIT   ] CWWKZ0001I: Application AcmeWebEjbEar started in 122.664 seconds.
[INFO] CWWKM2015I: Match number: 1 is [11/9/23, 14:26:45:938 PST] 00000031 com.ibm.ws.app.manager.AppMessageHelper                      A CWWKZ0001I: Application AcmeWebEjbEar started in 122.664 seconds..
.
.
[INFO] [AUDIT   ] CWWKZ0003I: The application AcmeWebEjbEar updated in 108.886 seconds.
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityPojoWSes/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS_CDI/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS/
[INFO] [AUDIT   ] CWWKZ0009I: The application AcmeWebEjbEar has stopped successfully.

It goes through this cycle a couple of times before the application is finally available. During these times - if I try to access the app url - I get Context Root not found.

Finally - when I see this message:

[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS_CDI/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityPojoWSes/
[INFO] [WARNING ] Settings: Could not parse struts.locale setting, substituting default VM locale
[INFO] [AUDIT   ] CWWKZ0003I: The application AcmeWebEjbEar updated in 106.687 seconds.

then the app is finally stable and I can access the app url.

@rumanaHaque
Copy link
Author

The prev errors were on Eclipse.
I do see the same errors in VScode as well.

warning: [options] To suppress warnings about obsolete options, use -Xlint:-options.
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityPojoWSes/
4 warnings
.
.
INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityPojoWSes/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKZ0009I: The application AcmeWebEjbEar has stopped successfully.
.
.
4 warnings
[INFO] AcmeAnnuityWeb source compilation was successful.
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityPojoWSes/
.
.

INFO] [AUDIT   ] CWWKZ0003I: The application AcmeWebEjbEar updated in 0.863 seconds.
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityPojoWSes/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKZ0009I: The application AcmeWebEjbEar has stopped successfully.
[INFO] [WARNING ] SRVE9967W: The manifest class path commons-dbcp-1.2.2.jar can not be found in jar file file:/Users/rumanahaque/Documents/Acme_ee10/acme-ee/AcmeAnnuityCommon/target/classes/ or its parent.
[INFO] [WARNING ] SRVE9967W: The manifest class path commons-pool-1.3.jar can not be found in jar file file:/Users/rumanahaque/Documents/Acme_ee10/acme-ee/AcmeAnnuityCommon/target/classes/ or its parent.
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/AnnuityPojoWSes/
[INFO] [WARNING ] CWNEN0046W: The jakarta.jms.ConnectionFactory type specified on the resource-ref, resource-env-ref, or message-destination-ref with the jms/ACMEAnnuityJMSConnectionFactory name in the AcmeAnnuityWeb.war module could not be loaded. Compatibility type checking will not be performed for this resource reference.
[INFO] [ERROR   ] SRVE0321E: The [struts2] filter did not load during start up.
[INFO] Filter [struts2]: org.apache.struts2.dispatcher.FilterDispatcher was found, but is missing another required class.
[INFO] 
[INFO] [AUDIT   ] CWWKZ0003I: The application AcmeWebEjbEar updated in 0.643 seconds.

@cherylking
Copy link
Member

Could be related to #699? Although Rumana did say she did not see the same behavior from the command line. Need to try and recreate from the cmd line ourselves to see.

@rumanaHaque
Copy link
Author

Update about command line. I just retried, and I see the same behavior from the command line as well. The issue is where I run the mvn liberty:dev command from.
If I run within the root - i.e - c:\eclipse-workspace\acme-ee10\acme-ee>mvn liberty:dev - I see the same problem as I see using the Liberty Tools Start - where it keeps on recompiling.

[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS_CDI/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://mum1.fyre.ibm.com:9080/AnnuityPojoWSes/
[INFO] [AUDIT   ] CWWKZ0003I: The application AcmeWebEjbEar updated in 22.712 seconds.
[INFO] [WARNING ] Settings: Could not parse struts.locale setting, substituting default VM locale
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityPojoWSes/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M2/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS11M1/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AnnuityJAXRS20/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityWeb/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS_CDI/
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://mum1.fyre.ibm.com:9080/AcmeAnnuityEJB3JAXWS/
[INFO] [AUDIT   ] CWWKZ0009I: The application AcmeWebEjbEar has stopped successfully.

However - if I run within the project AcmeWebEjbEar
c:\eclipse-workspace\acme-ee10\acme-ee\AcmeWebEjbEar>mvn liberty:dev
then it starts it only once and does not recompile.

@scottkurz
Copy link
Contributor

I've been experimenting with the CargoTracker Jakarta sample: https://github.com/eclipse-ee4j/cargotracker/

There seems to be a similar "thrashing" behavior where the app continually restarts upon update.

I accounted for the issue: #699 by building a local snapshot and hard-coding disabling the initial compile (the one we do AFTER the compile mojo runs). While this simplified the initial startup, I still experienced the same thing after later making an update once the app had been up and started.

There seems to be something app-related in play here. The cargo tracker uses EJB persistent timers and its JPA runs a startup script... not sure if either of those are related.

@scottkurz
Copy link
Contributor

@rumanaHaque can you please try to recreate with this trace: <logging traceSpecification="*=info:applications=all and please capture both:

  • the terminal/console log (mvn output)
  • a server dump /.../wlp/bin/server dump (or I guess just the 'logs' dir within but might as well ask for the whole dump)

I saw something similar w/ the cargotracker app...there I suspect it is some failures related to messaging & MDB init causing the thrashing..combined with the fact that restarting some of these messaging components forces an app recycle. I'm not too familiar with this from the runtime perspective.. so possibly we'd need a couple rounds of tracing to get to the bottom of this. Thank you !

@rumanaHaque
Copy link
Author

I added the server trace string as you mentioned in my server.xml file-
<logging traceSpecification="*=info:applications=all" maxFileSize="100" maxFiles="20" traceFileName="server_trace.log" />

I did an mvn clean, and started my server using the Liberty Tools dashboard.
I did not see any trace files generated.

These are the logs for the server after I started, and it also has the console.txt file where I tried to capture most of the console output.
logs.zip

I also got the server dump as you requested - by running this command.

c:\IBM\WAS\profiles\AppSrv02>C:\eclipse-workspace\acme-ee10\acme-ee\AcmeWebEjbEar\target\liberty\wlp\bin\server dump
Dumping server defaultServer.
Server defaultServer is not running.
Server defaultServer dump complete in C:\eclipse-workspace\acme-ee10\acme-ee\AcmeWebEjbEar\target\liberty\wlp\usr\servers\defaultServer\defaultServer.dump-23.12.11_10.32.56.zip.

Here is the server dump.
defaultServer.dump-23.12.11_10.32.56.zip

@scottkurz
Copy link
Contributor

scottkurz commented Dec 11, 2023

It looks to me like the <logging> element is not enabled in the server dump. That would be a big help. Could you please try again with the trace enabled when you get a chance?

@rumanaHaque
Copy link
Author

rumanaHaque commented Dec 11, 2023

Hi @scottkurz - Yes - sorry I had put the trace string in a diff server.xml in my workspace.
Here are the log files after I enabled trace in the correct server.xml.

logs.zip

And the server dump again.
defaultServer.dump-23.12.11_13.26.02.zip

@scottkurz
Copy link
Contributor

Discussed this more in DXDI call today: https://github.com/orgs/OpenLiberty/projects/23/views/3?pane=issue&itemId=50131096

I'm going to share some sketched out, incomplete thoughts here, though this doesn't even include detailed analysis of the captured trace, just some guesses based on a preliminary look at the logs captured back in Dec.

THOUGHTS

I wonder if this issue raises a weakness with the design assumption that we don't need an mbean notification on app update, (like we used in WDT/LDT).

This would potentially allow us to do a single app restart rather than multiple ones.

That said, I wouldn't think the app would just keep restarting if this were the core issue. I'd think it'd eventually settle down...but this is just a guess.

Looking into it a bit, it seems WDT builds a set of changed files and invokes the FileNotificationMBean passing this set, after which the Liberty runtime then (re)starts the app.

I also wonder if bumping up the polling rate could reduce the chance for this kind of situation. E.g. if we switched from 500ms to 5s would the mbean not be as important?

<applicationMonitor pollingRate="5s"/>

CONCLUSION

That's all for now, I'm not asking anyone to rerun anything, just sharing some of my own notes on the subject here.

@m-schutte-ohra-nl
Copy link
Contributor

We encountered the same problem with our apps going through several restarts at the initial liberty:dev execution (@scottkurz please note that Rumana does not speak of continually restarting but instead says "It goes through this cycle a couple of times before the application is finally available").

I took the suggestion from your previous comment and experimented with the applicationMonitor pollingRate. Setting it to more than what is required for the application startup time plus all the module's 'source compilation was successful/tests compilation was successful' calls indeed prevents the multiple restarts.

This however will make the liberty:dev experience a lot less responsive to code changes. The mbean notification mechanism would be my preferred solution, but perhaps an extra one letter command to restart the application is an easy to implement alternative.

Ofcourse, getting rid of the initial compile calls as described in #699 would also help.

@scottkurz
Copy link
Contributor

@m-schutte-ohra-nl, though I don't have any further updates on this issue, I just wanted to thank you for sharing your experience here.

@m-schutte-ohra-nl
Copy link
Contributor

@scottkurz This is still a real problem for us, can we expect progress to be made on this issue ?

@arunvenmany-ibm
Copy link
Contributor

arunvenmany-ibm commented Feb 4, 2025

Hi @rumanaHaque

The fix is included in the snapshot 3.11.3-SNAPSHOT. Please see the doc here for how to use a snapshot.

@cherylking
Copy link
Member

@m-schutte-ohra-nl Please let us know if the fix provided in the snapshot release helps with your issue. The fix mainly avoids recompiling when the compile was already successful (issue #699). There may be more changes needed to completely fix this issue though. So any feedback you can provide would be valuable. Thank you.

@m-schutte-ohra-nl
Copy link
Contributor

The test did not succeed. When using version 3.11.3-SNAPSHOT of the maven liberty plugin we get compilation errors because the generated JAXB and OpenAPI code is not found during compilation. See: liberty-log.txt

liberty-log.txt

@m-schutte-ohra-nl
Copy link
Contributor

m-schutte-ohra-nl commented Feb 13, 2025 via email

@arunvenmany-ibm
Copy link
Contributor

Hi @m-schutte-ohra-nl
can you share a sample project with necessary dependencies, so that we can analyze further?

@jvdsandt
Copy link

Hi @m-schutte-ohra-nl can you share a sample project with necessary dependencies, so that we can analyze further?

Hi @arunvenmany-ibm,
Here you can find a simple Liberty project that shows the issue: https://github.com/jvdsandt/liberty-test1

@scottkurz
Copy link
Contributor

scottkurz commented Feb 25, 2025

Thanks @jvdsandt . I see from the sample in: https://github.com/jvdsandt/liberty-test1
that the change #1858 seems to have an impact on compiling wsimport-generated classes in dev mode.

I haven't gotten a clear enough picture to summarize or maybe to recreate exactly, but I believe switching to compiler:compile@default-compile has changed this flow, and we should understand it better at least (if not revert it) before releasing 3.11.3

@arunvenmany-ibm
Copy link
Contributor

arunvenmany-ibm commented Feb 28, 2025

Hi @scottkurz

I checked out the sample project and run "mvn compile liberty:dev" together and the project is working fine. Attaching screen recording for reference
As you have suspected, issue is caused due to using default-compile as execution-id. I tested reverting back the changes of #1858, and the sample project is working with "mvn compile" and "mvn liberty:dev" as separate commands

Screen.Recording.2025-02-28.at.9.51.47.AM.mov

Attaching the execution logs for both individual and combined executions

compile_log_3.11.3.log
dev_log_3.11.3.log

combined_compile_dev_log_3.11.3.log

What I could understand is that when we use separate maven sessions, maven compiler plugin is unable to get the correct configurations for wsimport

Here you can see that when executing separately, wsimport sourceRoot is not part of compile configurations. Due to this, source is being recompiled and imported java files are being removed

Image

Image

Whereas, when we combine the commands, its taking up wsimport directory and no change in wsimport java files

Image

Image

I think we should revert as we cannot always make sure that the customer uses same maven session for all goals
Please confirm how to proceed with this

CC:- @cherylking

@arunvenmany-ibm
Copy link
Contributor

Hi @m-schutte-ohra-nl @jvdsandt

We have removed the changes related to default-compile and a new snapshot has been generated
https://github.com/jvdsandt/liberty-test1 is working fine now.
Please try with the updated snapshot on your original project
Attaching logs

3.11.3-SNAPSHOT.log

@arunvenmany-ibm
Copy link
Contributor

arunvenmany-ibm commented Mar 3, 2025

Hi @rumanaHaque
Please use 3.11.3-SNAPSHOT and test "multiple restart" issue on was-svt acme-ee project

I have tested on acme-ee11 and acme-ee10 branch and now multiple restart is not happening

Attaching before and after logs. Please test and confirm from your end

3.11.2.log
3.11.3-SNAPSHOT.log

@jvdsandt
Copy link

jvdsandt commented Mar 4, 2025

Hi @arunvenmany-ibm

We did a retest with our original project and now the server starts up correctly and there are no more multiple restarts. So, it's looking good from our side!

@rumanaHaque
Copy link
Author

I retried this with the latest version of acme-ee10, and I don't see the restarts any more.
Here are my logs with 3.11.2 and 3.11.3.

Acme-ee10-3.11.2.log

Acme-ee10-3.11.3_SNAPSHOT.log

There are no restarts and I also see these messages in the 3.11.3_SNAPSHOT.

INFO] Recompile skipped for acme-ee10 since earlier compilation is successful\
[INFO] Recompile skipped for AcmeCommon since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityCommon since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityJAXRSCommon since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityEJB3 since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityEJB3JAXWS since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityEJB3JAXWS_CDI since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityEJB3MDB since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityJAXRSWSes_jaxrs11_m1 since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityJAXRSWSes_jaxrs11_m2 since earlier compilation is successful\
[INFO] Recompile skipped for AcmeAnnuityJAXRSWSes_jaxrs20 since earlier compilation is successful\

@m-schutte-ohra-nl
Copy link
Contributor

Just to document where we are right now: with 3.11.3 the problem is solved for the initial startup. However, when we do a code change after this, it remains.

Could you please consider the earlier suggestion of introducing a new one letter command for liberty:dev to restart the application(s) by means of an mbean call? Combined with updateTrigger="mbean" this would provide a workable solution for us.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants