IBM Security Verify

 View Only
  • 1.  Cleaning up messages.log and trace.log from AAC/Federation

    IBM Champion
    Posted Fri September 27, 2019 09:11 AM
    Hello everybody,
    We are trying to clean our logs and trace file as much as possible to only keep important information.

    We have found that in the messages.log and trace.log files from AAC/Federation modules most of the content is made of stack traces that are logged each time an invalid OAuth token is received.
    For reference, here below is what it looks like.

    We wish to replace all those useless lines by a single one, or even none at all.

    As this seems to be logged before the execution of the mapping rules, we have found no way to modify the default behavior and disable this logging.

    -=> Is this something that is possible at the moment ?

    Our production aac/federation logs are filled by theses repetitive and useless logs that represent more than 95% of the content of those files. As we plan to also send those logs to Splunk, we need a way to keep only what is useful.

    Best regards

    [9/27/19 14:47:02:568 CEST] 000c1cf1 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E No client ID found for token ID cMQjy1Oyzb4r6Q0QJ2Es
    [9/27/19 14:47:02:569 CEST] 000c1cf1 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E OAuth mapping rule missing for client ID null
    [9/27/19 14:47:02:581 CEST] 000c1cf1 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E No client ID found for token ID cMQjy1Oyzb4r6Q0QJ2Es
    [9/27/19 14:47:02:582 CEST] 000c1cf1 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E OAuth mapping rule missing for client ID null
    [9/27/19 14:47:02:583 CEST] 000c1cf1 com.tivoli.am.fim.oauth20.util.OAuth20ContextHelper          I com.tivoli.am.fim.oauth20.exception.OAuth20InvalidTokenException: FBTOAU211E The [access_token] received of type [bearer] does not exist.
    	at com.tivoli.am.fim.oauth20.util.OAuth20ContextHelper.getOAuth20Token(OAuth20ContextHelper.java:511)
    	at com.tivoli.am.fim.oauth20.util.OAuth20ContextHelper.getOAuth20Token(OAuth20ContextHelper.java:489)
    	at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.resourceRequest(OAuth20TokenModule.java:1217)
    	at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.doMap(OAuth20TokenModule.java:228)
    	at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.invoke(OAuth20TokenModule.java:127)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChain.invoke(STSModuleChain.java:319)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChainManager.executeChain(STSModuleChainManager.java:1083)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChainManager.processthroughChains(STSModuleChainManager.java:170)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChainManager.process(STSModuleChainManager.java:117)
    	at com.tivoli.am.fim.trustserver.sts.STSManager.process(STSManager.java:60)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenProcessor.process(SecurityTokenProcessor.java:63)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenService.processRequest(SecurityTokenService.java:574)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenService.processRequestSecurityToken(SecurityTokenService.java:525)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenService.requestSecurityTokenJaxWS(SecurityTokenService.java:323)
    	at com.tivoli.am.fim.fedmgr2.servlet.SPSCommandDispatcher.invoke(SPSCommandDispatcher.java:542)
    	at com.tivoli.am.fim.sts.jaxws.providers.FimWsTrustStsDispatcher.dispatch(FimWsTrustStsDispatcher.java:144)
    	at com.tivoli.am.fim.sts.jaxws.providers.WST13TrustServiceProvider.invoke(WST13TrustServiceProvider.java:66)
    	at com.tivoli.am.fim.sts.jaxws.providers.WST13TrustServiceProvider.invoke(WST13TrustServiceProvider.java:42)
    	at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
    	at java.lang.reflect.Method.invoke(Method.java:508)
    	at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:180)
    	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96)
    	at org.apache.cxf.jaxws.AbstractJAXWSMethodInvoker.invoke(AbstractJAXWSMethodInvoker.java:178)
    	at org.apache.cxf.jaxws.JAXWSMethodInvoker.invoke(JAXWSMethodInvoker.java:72)
    	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:75)
    	at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58)
    	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:522)
    	at java.util.concurrent.FutureTask.run(FutureTask.java:277)
    	at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37)
    	at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:107)
    	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262)
    	at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121)
    	at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:212)
    	at com.ibm.ws.jaxws.endpoint.AbstractJaxWsWebEndpoint.invoke(AbstractJaxWsWebEndpoint.java:181)
    	at com.ibm.ws.jaxws.webcontainer.LibertyJaxWsServlet.handleRequest(LibertyJaxWsServlet.java:134)
    	at com.ibm.ws.jaxws.webcontainer.LibertyJaxWsServlet.doPost(LibertyJaxWsServlet.java:93)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:706)
    	at com.ibm.ws.jaxws.webcontainer.LibertyJaxWsServlet.service(LibertyJaxWsServlet.java:85)
    	at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1255)
    	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:743)
    	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:440)
    	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1208)
    	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1005)
    	at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:75)
    	at com.ibm.ws.webcontainer40.servlet.CacheServletWrapper40.handleRequest(CacheServletWrapper40.java:83)
    	at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:927)
    	at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:279)
    	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1011)
    	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:414)
    	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:373)
    	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:532)
    	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:466)
    	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:331)
    	at com.ibm.ws.http.channel.internal.inbound.HttpICLReadCallback.complete(HttpICLReadCallback.java:70)
    	at com.ibm.ws.channel.ssl.internal.SSLReadServiceContext$SSLReadCompletedCallback.complete(SSLReadServiceContext.java:1803)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager.requestComplete(WorkQueueManager.java:501)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager.attemptIO(WorkQueueManager.java:571)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager.workerRun(WorkQueueManager.java:926)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager$Worker.run(WorkQueueManager.java:1015)
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    	at java.lang.Thread.run(Thread.java:812)
    
    [9/27/19 14:47:02:586 CEST] 000c1cf1 com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule I com.tivoli.am.fim.oauth20.exception.OAuth20InvalidTokenException: FBTOAU211E The [access_token] received of type [bearer] does not exist.
    	at com.tivoli.am.fim.oauth20.util.OAuth20ContextHelper.getOAuth20Token(OAuth20ContextHelper.java:511)
    	at com.tivoli.am.fim.oauth20.util.OAuth20ContextHelper.getOAuth20Token(OAuth20ContextHelper.java:489)
    	at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.resourceRequest(OAuth20TokenModule.java:1217)
    	at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.doMap(OAuth20TokenModule.java:228)
    	at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.invoke(OAuth20TokenModule.java:127)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChain.invoke(STSModuleChain.java:319)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChainManager.executeChain(STSModuleChainManager.java:1083)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChainManager.processthroughChains(STSModuleChainManager.java:170)
    	at com.tivoli.am.fim.trustserver.sts.STSModuleChainManager.process(STSModuleChainManager.java:117)
    	at com.tivoli.am.fim.trustserver.sts.STSManager.process(STSManager.java:60)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenProcessor.process(SecurityTokenProcessor.java:63)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenService.processRequest(SecurityTokenService.java:574)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenService.processRequestSecurityToken(SecurityTokenService.java:525)
    	at com.tivoli.am.fim.trustserver.service.SecurityTokenService.requestSecurityTokenJaxWS(SecurityTokenService.java:323)
    	at com.tivoli.am.fim.fedmgr2.servlet.SPSCommandDispatcher.invoke(SPSCommandDispatcher.java:542)
    	at com.tivoli.am.fim.sts.jaxws.providers.FimWsTrustStsDispatcher.dispatch(FimWsTrustStsDispatcher.java:144)
    	at com.tivoli.am.fim.sts.jaxws.providers.WST13TrustServiceProvider.invoke(WST13TrustServiceProvider.java:66)
    	at com.tivoli.am.fim.sts.jaxws.providers.WST13TrustServiceProvider.invoke(WST13TrustServiceProvider.java:42)
    	at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
    	at java.lang.reflect.Method.invoke(Method.java:508)
    	at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:180)
    	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96)
    	at org.apache.cxf.jaxws.AbstractJAXWSMethodInvoker.invoke(AbstractJAXWSMethodInvoker.java:178)
    	at org.apache.cxf.jaxws.JAXWSMethodInvoker.invoke(JAXWSMethodInvoker.java:72)
    	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:75)
    	at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58)
    	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:522)
    	at java.util.concurrent.FutureTask.run(FutureTask.java:277)
    	at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37)
    	at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:107)
    	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262)
    	at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121)
    	at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:212)
    	at com.ibm.ws.jaxws.endpoint.AbstractJaxWsWebEndpoint.invoke(AbstractJaxWsWebEndpoint.java:181)
    	at com.ibm.ws.jaxws.webcontainer.LibertyJaxWsServlet.handleRequest(LibertyJaxWsServlet.java:134)
    	at com.ibm.ws.jaxws.webcontainer.LibertyJaxWsServlet.doPost(LibertyJaxWsServlet.java:93)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:706)
    	at com.ibm.ws.jaxws.webcontainer.LibertyJaxWsServlet.service(LibertyJaxWsServlet.java:85)
    	at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1255)
    	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:743)
    	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:440)
    	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1208)
    	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1005)
    	at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:75)
    	at com.ibm.ws.webcontainer40.servlet.CacheServletWrapper40.handleRequest(CacheServletWrapper40.java:83)
    	at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:927)
    	at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:279)
    	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1011)
    	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:414)
    	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:373)
    	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:532)
    	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:466)
    	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:331)
    	at com.ibm.ws.http.channel.internal.inbound.HttpICLReadCallback.complete(HttpICLReadCallback.java:70)
    	at com.ibm.ws.channel.ssl.internal.SSLReadServiceContext$SSLReadCompletedCallback.complete(SSLReadServiceContext.java:1803)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager.requestComplete(WorkQueueManager.java:501)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager.attemptIO(WorkQueueManager.java:571)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager.workerRun(WorkQueueManager.java:926)
    	at com.ibm.ws.tcpchannel.internal.WorkQueueManager$Worker.run(WorkQueueManager.java:1015)
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    	at java.lang.Thread.run(Thread.java:812)
    
    [9/27/19 14:47:02:591 CEST] 000c1cf1 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E No client ID found for token ID cMQjy1Oyzb4r6Q0QJ2Es
    [9/27/19 14:47:02:592 CEST] 000c1cf1 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E OAuth mapping rule missing for client ID null
    ​


    ------------------------------
    André Leruitte
    ------------------------------


  • 2.  RE: Cleaning up messages.log and trace.log from AAC/Federation

    Posted Wed December 04, 2019 04:46 PM
    Hello,

    we have the same problem in message.log of aac. Logs are really filling up with these errors. Does anybody know what this messages mean and is there a way to get rid of them?

    ------------------------------
    Jürgen Hitt
    ------------------------------



  • 3.  RE: Cleaning up messages.log and trace.log from AAC/Federation

    Posted Thu December 05, 2019 06:44 PM

    Hi André and Jürgen,

    What trace packages and levels do you have configured?

    If you check the log, you can see the level of the different messages, for example the exception is at level INFO because of the I after OAuth20TokenModule:

    [9/27/19 14:47:02:586 CEST] 000c1cf1 com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule I com.tivoli.am.fim.oauth20.exception.OAuth20InvalidTokenException


    Whereas the other messages have level ERROR (E after OAuth20MappingRuleSTSModule)


    Enabling tracing at a given level also enables tracing at all higher levels, i.e. enabling trace at FINE will include:
    FINE, DETAIL, CONFIG, INFO, AUDIT, WARNING, SEVERE, FATAL

    The trace levels in the UI are in order of lowest level to highest level. So you can get rid of the exception by changing the configured level to one higher than INFO (lower down in the UI list), like AUDIT or WARNING

    Hope this helps



    ------------------------------
    Jasmine
    ------------------------------



  • 4.  RE: Cleaning up messages.log and trace.log from AAC/Federation

    IBM Champion
    Posted Fri December 06, 2019 03:00 AM
    Thank you Jasmine.

    We are going to test your suggestion by trying to set the tracing to :
    - com.tivoli.am.fim.trustserver.sts.utilities.IDMappingExtUtils=AUDIT

    But first we will have to switch all our own logs to AUDIT level (instead of INFO) so we still be able to have them.

    ------------------------------
    André Leruitte
    ------------------------------



  • 5.  RE: Cleaning up messages.log and trace.log from AAC/Federation

    Posted Fri December 06, 2019 03:44 AM
    ​Hello Jasmine,

    in our case we have no tracing level at all in AAC/Fed runtime. On the production stage we only enable tracing if required for a limited time (e.g. problem analysis).

    However, we still get "I" and "E" messages in message.log. Some examples:

    11        [12/6/19 9:31:44:713 CET] 00214f30 com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule I com.tivoli.am.fim.oauth20.exception.OAuth20InvalidTokenException: FBTOAU211E The [access_token] received of type [bearer] does not exist.
    12         at com.tivoli.am.fim.oauth20.util.OAuth20ContextHelper.getOAuth20Token(OAuth20ContextHelper.java:511)
    13         at com.tivoli.am.fim.oauth20.util.OAuth20ContextHelper.getOAuth20Token(OAuth20ContextHelper.java:489)
    14         at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.resourceRequest(OAuth20TokenModule.java:1224)
    15         at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.doMap(OAuth20TokenModule.java:228)
    16         at com.tivoli.am.fim.trustserver.sts.modules.OAuth20TokenModule.invoke(OAuth20TokenModule.java:127)
    17         at com.tivoli.am.fim.trustserver.sts.STSModuleChain.invoke(STSModuleChain.java:319)
    18         at com.tivoli.am.fim.trustserver.sts.STSModuleChainManager.executeChain
    319       [12/6/19 9:09:44:579 CET] 00214b68 com.tivoli.am.fim.user.info.jdbc.JDBCUserInfoDBHelperImpl    I DB type: Oracle
    563       [12/6/19 9:09:56:767 CET] 00214b71 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E No client ID found for token ID Vmb9bijsIwQB2ZU7MwfJ
    564       [12/6/19 9:09:56:769 CET] 00214b71 i.am.fim.trustserver.sts.modules.OAuth20MappingRuleSTSModule E OAuth mapping rule missing for client ID null

    This is only in message.log. The trace.log is empty (which probably is the correct behaviour since we have no tracing enabled).

    Is there a need to set the trace level?

    ------------------------------
    Jürgen Hitt
    ------------------------------



  • 6.  RE: Cleaning up messages.log and trace.log from AAC/Federation

    Posted Tue December 10, 2019 06:20 PM
    André, sounds like that will work for you, awesome!

    Jürgen, I had a look through the ISAM and Liberty docs and I couldn't see any parameters that control the levels printed to message.log. Unfortunately it looks like it always includes INFO, AUDITWARNINGERRORFAILURE.


    ------------------------------
    Jasmine
    ------------------------------