Open rumanaHaque opened 1 year ago
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.
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.
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.
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: https://github.com/OpenLiberty/ci.maven/issues/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.
@rumanaHaque can you please try to recreate with this trace: <logging traceSpecification="*=info:applications=all
and please capture both:
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 !
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
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?
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.
And the server dump again. defaultServer.dump-23.12.11_13.26.02.zip
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.
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"/>
That's all for now, I'm not asking anyone to rerun anything, just sharing some of my own notes on the subject here.
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.
@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.
@scottkurz This is still a real problem for us, can we expect progress to be made on this issue ?
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:
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
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:
then the app is finally stable and I can access the app url.