OpenLiberty / open-liberty

Open Liberty is a highly composable, fast to start, dynamic application server runtime environment
https://openliberty.io
Eclipse Public License 2.0
1.14k stars 587 forks source link

SVT: variable not refreshed after initial access when server.xml updated #4436

Closed hanczaryk closed 6 years ago

hanczaryk commented 6 years ago

I was attempting to follow https://github.com/OpenLiberty/open-liberty/issues/3993 to define a MicroProfile application's configuration through the server.xml file.

I've pulled down the latest CL Xo 8/2 build.

My SVT ProShop application has 3 servlets that among other things print out the sessionId and variable config.test.dsvalue.

My 3 servlets (Drivers, Drivers12, and Drivers13) inject the config property in the following manner. ###################################### Drivers.java @Inject @ConfigProperty(name="config.test.dsvalue", defaultValue="dsvalue_from_default") String whichDS;

Drivers12.java @Inject @ConfigProperty(name="config.test.dsvalue", defaultValue="dsvalue_from_default") private List propValue;

Drivers13.java @Inject @ConfigProperty(name="config.test.dsvalue", defaultValue="dsvalue_from_default") private List propValue; ######################################

In this example to clearly detail my steps, I have the following variable setup prior to starting my Liberty server.

My execution steps are as follows from my local VM. 1) I start the server and hit my /Drivers servlet. I successfully view that whichDS is reported as startupValue. 2) I edit the server.xml and change value to "edit1Value" and then hit my /Drivers12 servlet. I successfully view that propValue.get(0) is reported as edit1Value. 3) I edit the server.xml and change the value to "edit2Value" and then hit my /Drivers13 servlet. I successfully view that propValue.get(0) is reported as edit2Value. 4) Finally, I edit the server.xml and change the value to "finalValue" and then attempt to hit my 3 servlets. At this point, I expect that "finalValue" will be reported, but what actually gets reported is /Drivers shows startupValue, /Drivers12 shows edit1Value, and /Drivers13 shows edit2Value.

I initially thought this might be a Chrome caching issue, but I've run with clearing the cache and I get the same results. I also hit the servlets from another machine that would not have cached the pages and get the same results.

FYI, here is a link to source code for Drivers.java https://github.ibm.com/hanczar-maven/ProShop/blob/master/src/main/java/myservlets/Drivers.java

neilgsyoung commented 6 years ago

Hello @hanczaryk please could you recreate with trace enabled? So a trace string like...

trace.specification="*=info:APPCONFIG=all"

....should give us the info we need. And it'd be good to have the messages.log and any FFDCs too. Thanks.

hanczaryk commented 6 years ago

I've recreated with the traceSpec above. I've zipped and uploaded the logs directory to http://rtpgsa.ibm.com/home/h/a/hanczar/web/public/testRep/bugs/4436/8-6/logs.zip

neilgsyoung commented 6 years ago

Thanks for the logs. I can see the config being refreshed 3 times, [8/6/18 11:09:37:040 EDT] 00000053 id=00000000 com.ibm.ws.config.xml.internal.ConfigRefresher A CWWKG0017I: The server configuration was successfully updated in 0.035 seconds. [8/6/18 11:10:11:627 EDT] 0000006c id=00000000 com.ibm.ws.config.xml.internal.ConfigRefresher A CWWKG0017I: The server configuration was successfully updated in 0.013 seconds. [8/6/18 11:10:52:272 EDT] 0000007b id=00000000 com.ibm.ws.config.xml.internal.ConfigRefresher A CWWKG0017I: The server configuration was successfully updated in 0.014 seconds.

And each time the config is refreshed, I can see the mpConfig respond to the update (with a slight delay as the mechanism is based on polling). So mpConfig picks up the final change to the variable here,

[8/6/18 11:10:52:569 EDT] 00000077 id=00000000 com.ibm.ws.microprofile.config13.sources.OSGiConfigUtils < getVariableFromServerXML Exit
{config.test.dsvalue=finalValue}

So......I think I need to see the application. Is it possible to zip that up for me too? Just wondering if there's a CDI scope issue. Thanks.

hanczaryk commented 6 years ago

The ProShop app source code is on github with the direct link to the Drivers servlet at https://github.ibm.com/hanczar-maven/ProShop/blob/master/src/main/java/myservlets/Drivers.java

neilgsyoung commented 6 years ago

Ah, sorry, you'd already put that link at the top of the issue!!

The problem is that the whichDS variable is scoped on Servlet initialization - which is why you see those symptoms. In our FAT tests,

https://github.com/OpenLiberty/open-liberty/blob/integration/dev/com.ibm.ws.microprofile.config.1.3_fat/test-applications/variableServerXMLApp/src/com/ibm/ws/microprofile/config13/variableServerXML/web/VariableServerXMLServlet.java

we inject a RequestScoped bean into the servlet,

@Inject  VariableServerXMLBean bean;

and the Bean references a raft of ConfigPropertys,

@RequestScoped public class VariableServerXMLBean { @Inject @ConfigProperty(name = "changeable_variable") String changeableVariable; ...

which pick up the latest server.xml value on each Request. Hope this helps. Thanks.

hanczaryk commented 6 years ago

Neil, Thanks for the info. I updated my ProShop implementation to inject RequestScoped bean and I now observe the correct functionality. Thanks for helping me work through the issue. As such, I'm closing this issue.