Minor Description
If a user is not in the WS authorized user group, it outputs an error to the client, with a full stack trace. In the WS log it outputs a full stacktrace at ERROR level, then the full output going to the client which includes the same stack trace at ERROR level, then the GrouperWsLog class does the same 2 outputs but at DEBUG level. This results in 167+ lines of output.
There are a few things that could be improved.
(1) The client doesn't need a stacktrace for an unauthorized user error. It just needs the error message
2) When the user access error is caught by GrouperServiceJ2ee, it is a runtime exception. Since this is a known error condition, it could be changed to some other exception class. These expected exception types wouldn't need a full stack trace, and only the real runtime exceptions should get a full stack trace.
3) We have set GrouperWsLog to DEBUG level because it logs timing and user login information from all WS calls. Does this also need to dump a full stacktrace for errors at DEBUG level? Are there any cases where the caller hasn't already done so?
Sample stack trace
Request: GET https://grouper.localhosdt/grouper-ws/servicesRest/json/v2_5_000/groups/group:path/members
2021-07-20 15:45:25,873: [http-apr-8080-exec-3] INFO WsGrouperKerberosAuthenticationNoJaas.retrieveLoggedInSubjectId(84) - Retrieved cached login for cer28
|
2021-07-20 15:45:25,874: [http-apr-8080-exec-3] ERROR GrouperServiceJ2ee.retrieveSubjectActAsHelper(662) - user: '730104343' is not a member of group: 'etc:access:ws:ws_users', and therefore is not authorized to use the app (configured in local media.properties penn.uiGroup
|
java.lang.RuntimeException: User is not authorized: Subject id: 730104343, sourceId: pid, name: Chad Redman
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAsHelper(GrouperServiceJ2ee.java:658)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAs(GrouperServiceJ2ee.java:593)
|
at edu.internet2.middleware.grouper.ws.util.GrouperServiceUtils.retrieveGrouperSession(GrouperServiceUtils.java:848)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembers(GrouperServiceLogic.java:1579)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembersLite(GrouperServiceLogic.java:2375)
|
at edu.internet2.middleware.grouper.ws.coresoap.GrouperService.getMembersLite(GrouperService.java:402)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperServiceRest.getMembersLite(GrouperServiceRest.java:249)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGetGroup$1.service(GrouperWsRestGetGroup.java:66)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGet$1.service(GrouperWsRestGet.java:127)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperRestHttpMethod$1.service(GrouperRestHttpMethod.java:57)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperRestServlet.service(GrouperRestServlet.java:202)
|
at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.doFilter(GrouperServiceJ2ee.java:1007)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
|
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
|
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
|
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
|
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
|
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
|
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
|
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:528)
|
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1100)
|
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:687)
|
at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2458)
|
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
|
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
|
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
|
at java.lang.Thread.run(Thread.java:748)
|
2021-07-20 15:45:25,874: [http-apr-8080-exec-3] ERROR WsGetMembersResults.assignResultCodeException(142) - clientVersion: 2.5.0, wsGroupLookups: Array size: 1: [0]: WsGroupLookup[pitGroups=[],groupName=unc:app:its:mfa:csod:sources:csod-learning-admins]
|
|
|
, memberFilter: All, includeSubjectDetail: false, actAsSubject: null, fieldName: null, subjectAttributeNames: null
|
, paramNames:
|
, params: null
|
, sourceIds: null
|
, pointInTimeFrom: null, pointInTimeTo: null, pageSize: null, pageNumber: null, sortString: null, ascending: null
|
java.lang.RuntimeException: User is not authorized
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAsHelper(GrouperServiceJ2ee.java:664)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAs(GrouperServiceJ2ee.java:593)
|
at edu.internet2.middleware.grouper.ws.util.GrouperServiceUtils.retrieveGrouperSession(GrouperServiceUtils.java:848)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembers(GrouperServiceLogic.java:1579)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembersLite(GrouperServiceLogic.java:2375)
|
at edu.internet2.middleware.grouper.ws.coresoap.GrouperService.getMembersLite(GrouperService.java:402)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperServiceRest.getMembersLite(GrouperServiceRest.java:249)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGetGroup$1.service(GrouperWsRestGetGroup.java:66)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGet$1.service(GrouperWsRestGet.java:127)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperRestHttpMethod$1.service(GrouperRestHttpMethod.java:57)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperRestServlet.service(GrouperRestServlet.java:202)
|
at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.doFilter(GrouperServiceJ2ee.java:1007)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
|
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
|
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
|
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
|
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
|
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
|
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
|
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:528)
|
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1100)
|
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:687)
|
at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2458)
|
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
|
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
|
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
|
at java.lang.Thread.run(Thread.java:748)
|
Caused by: java.lang.RuntimeException: User is not authorized: Subject id: 730104343, sourceId: pid, name: Chad Redman
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAsHelper(GrouperServiceJ2ee.java:658)
|
... 34 more
|
2021-07-20 15:45:25,875: [http-apr-8080-exec-3] DEBUG GrouperWsLog.wsLog(117) - start: 15:45:25.873, remoteAddr: 172.27.130.240, requestUrl: https://grouperspt.itsapps.unc.edu/grouper-ws/servicesRest/json/v2_5_000/groups/unc:app:its:mfa:csod:sources:csod-learning-admins/members, lite: true, clientVersion: 2.5.0, wsGroupLookups: Array size: 1: [0]: name: unc:app:its:mfa:csod:sources:csod-learning-admins, memberFilter: All, includeGroupDetail: false, includeSubjectDetail: false, pointInTimeRetrieve: false, pageIsCursor: false, pageCursorFieldIncludesLastRetrieved: false, userIdLoggedIn: cer28, userIdLoggedInSource: pid, userIdLoggedInSubjectId: 730104343, exception: java.lang.RuntimeException: User is not authorized
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAsHelper(GrouperServiceJ2ee.java:664)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAs(GrouperServiceJ2ee.java:593)
|
at edu.internet2.middleware.grouper.ws.util.GrouperServiceUtils.retrieveGrouperSession(GrouperServiceUtils.java:848)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembers(GrouperServiceLogic.java:1579)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembersLite(GrouperServiceLogic.java:2375)
|
at edu.internet2.middleware.grouper.ws.coresoap.GrouperService.getMembersLite(GrouperService.java:402)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperServiceRest.getMembersLite(GrouperServiceRest.java:249)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGetGroup$1.service(GrouperWsRestGetGroup.java:66)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGet$1.service(GrouperWsRestGet.java:127)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperRestHttpMethod$1.service(GrouperRestHttpMethod.java:57)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperRestServlet.service(GrouperRestServlet.java:202)
|
at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.doFilter(GrouperServiceJ2ee.java:1007)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
|
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
|
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
|
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
|
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
|
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
|
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
|
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:528)
|
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1100)
|
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:687)
|
at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2458)
|
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
|
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
|
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
|
at java.lang.Thread.run(Thread.java:748)
|
Caused by: java.lang.RuntimeException: User is not authorized: Subject id: 730104343, sourceId: pid, name: Chad Redman
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAsHelper(GrouperServiceJ2ee.java:658)
|
... 34 more
|
, success: F, resultCode: EXCEPTION, resultMessage: clientVersion: 2.5.0, wsGroupLookups: Array size: 1: [0]: WsGroupLookup[pitGroups=[],groupName=unc:app:its:mfa:csod:sources:csod-learning-admins]
|
|
|
, memberFilter: All, includeSubjectDetail: false, actAsSubject: null, fieldName: null, subjectAttributeNames: null
|
, paramNames:
|
, params: null
|
, sourceIds: null
|
, pointInTimeFrom: null, pointInTimeTo: null, pageSize: null, pageNumber: null, sortString: null, ascending: null, java.lang.RuntimeException: User is not authorized
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAsHelper(GrouperServiceJ2ee.java:664)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAs(GrouperServiceJ2ee.java:593)
|
at edu.internet2.middleware.grouper.ws.util.GrouperServiceUtils.retrieveGrouperSession(GrouperServiceUtils.java:848)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembers(GrouperServiceLogic.java:1579)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.getMembersLite(GrouperServiceLogic.java:2375)
|
at edu.internet2.middleware.grouper.ws.coresoap.GrouperService.getMembersLite(GrouperService.java:402)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperServiceRest.getMembersLite(GrouperServiceRest.java:249)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGetGroup$1.service(GrouperWsRestGetGroup.java:66)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestGet$1.service(GrouperWsRestGet.java:127)
|
at edu.internet2.middleware.grouper.ws.rest.method.GrouperRestHttpMethod$1.service(GrouperRestHttpMethod.java:57)
|
at edu.internet2.middleware.grouper.ws.rest.GrouperRestServlet.service(GrouperRestServlet.java:202)
|
at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.doFilter(GrouperServiceJ2ee.java:1007)
|
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
|
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
|
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
|
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
|
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
|
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
|
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
|
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
|
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
|
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:528)
|
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1100)
|
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:687)
|
at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2458)
|
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
|
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
|
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
|
at java.lang.Thread.run(Thread.java:748)
|
Caused by: java.lang.RuntimeException: User is not authorized: Subject id: 730104343, sourceId: pid, name: Chad Redman
|
at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.retrieveSubjectActAsHelper(GrouperServiceJ2ee.java:658)
|
... 34 more, serverVersion: 2.5.39, resultsSize: 0, elapsedMillis: 2
|
|