Log file has NPE when loading logging

[bbockelm]

This is round 2 of #106 . After the upgrade to 5.4.1, we now get:

Nov 18, 2023 2:35:23 PM edu.uiuc.ncsa.security.core.util.MyLoggingFacade error
SEVERE: could not load configuration
edu.uiuc.ncsa.security.core.exceptions.GeneralException: Unable to create client environment
	at edu.uiuc.ncsa.oa4mp.oauth2.client.OA2ClientLoader.createInstance(OA2ClientLoader.java:135)
	at edu.uiuc.ncsa.oa4mp.oauth2.client.OA2ClientLoader.createInstance(OA2ClientLoader.java:372)
	at edu.uiuc.ncsa.oa4mp.oauth2.client.OA2ClientLoader.createInstance(OA2ClientLoader.java:43)
	at edu.uiuc.ncsa.myproxy.oa4mp.client.loader.AbstractClientLoader.load(AbstractClientLoader.java:265)
	at edu.uiuc.ncsa.myproxy.oa4mp.client.loader.AbstractClientLoader.load(AbstractClientLoader.java:30)
	at edu.uiuc.ncsa.security.util.cli.ConfigurableCommandsImpl.getEnvironment(ConfigurableCommandsImpl.java:196)
	at edu.uiuc.ncsa.myproxy.oauth2.tools.OA2CLCCommands.<init>(OA2CLCCommands.java:127)
	at edu.uiuc.ncsa.oa2.servlet.ProxyUtils.getCLC(ProxyUtils.java:201)
	at edu.uiuc.ncsa.oa2.servlet.ProxyUtils.userCodeToProxyRedirect(ProxyUtils.java:182)
	at edu.uiuc.ncsa.oa2.servlet.RFC8628AuthorizationServer.processRequest(RFC8628AuthorizationServer.java:371)
	at edu.uiuc.ncsa.oa2.servlet.RFC8628AuthorizationServer.doIt(RFC8628AuthorizationServer.java:158)
	at edu.uiuc.ncsa.security.servlet.AbstractServlet.doPost(AbstractServlet.java:210)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:696)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:779)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:177)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:660)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
	at org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:426)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:87)
	at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalArgumentException: Error: no serviceUri specified in the configuration file
	at edu.uiuc.ncsa.myproxy.oa4mp.client.loader.AbstractClientLoader.getBaseURI(AbstractClientLoader.java:232)
	at edu.uiuc.ncsa.myproxy.oa4mp.client.loader.AbstractClientLoader.getAccessTokenURI(AbstractClientLoader.java:240)
	at edu.uiuc.ncsa.oa4mp.oauth2.client.OA2ClientLoader.createInstance(OA2ClientLoader.java:102)
	... 34 more

Note there's the new "Caused by" part of the stack trace. Here's the proxy-config.xml with various parts redacted:

<config>
    <client name="proxy-client">
        <logging
                logFileName="/dev/stdout"
                logName="oa4mp"
                logFileCount="1"
                debug="trace"/>
        <id>REDACTED</id>
        <secret>REDACTED</secret>
        <callbackUri>https://REDACTED/scitokens-server/ready</callbackUri>
        <serviceUri>https://cilogon.org/oauth2</serviceUri>
        <authorizeUri>https://cilogon.org/authorize</authorizeUri>
        <wellKnownUri>https://cilogon.org/oauth2/.well-known/openid-configuration</wellKnownUri>
        <scopes>
            <scope enabled="false">email</scope>
            <scope>openid</scope>
            <scope enabled="false">profile</scope>
            <scope>org.cilogon.userinfo</scope>
            <scope enabled="false">edu.uiuc.ncsa.myproxy.getcert</scope>
        </scopes>
        <memoryStore><assetStore/></memoryStore>
    </client>

</config>

There must be an ordering issue as you can clearly see the serviceUri is set!

[jbasney]

fixed in https://github.com/ncsa/oa4mp/releases/tag/v5.4.2 ?