记一次接口授权导致的500异常排查

Posted 2023-02-19 Java_Chuck

tags:

篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了记一次接口授权导致的500异常排查相关的知识，希望对你有一定的参考价值。

有一个导出的接口通过postman调用是返回正常的响应体，但是发布到测试环境，通过浏览器请求时，会返回500

通过浏览器请求

通过Postman请求

开始排查

整个链路为nginx -> spring cloud gateway -> 业务服务

首先从业务服务开始排查，增加一个log过滤器，打印下请求响应信息

2021-05-24 14:43:00.447 aom-platform-[,] [http-nio-9991-exec-9] ERROR o.a.c.c.C.[.[.[.[dispatcherServlet][175] - Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is com.sf.mrm.core.exception.BaseException: 接口未授权] with root cause
com.sf.mrm.core.exception.BaseException: 接口未授权
	at com.sf.aom.platform.aop.RoleRightInterceptor.Interceptor(RoleRightInterceptor.java:70)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633)
	at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
	at com.sf.aom.platform.controller.pc.CustomDeviceCategoryRest$$EnhancerBySpringCGLIB$$24c40d74.export(<generated>)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:800)
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:981)
	at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:884)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:858)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.github.xiaoymin.knife4j.spring.filter.ProductionSecurityFilter.doFilter(ProductionSecurityFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.github.xiaoymin.knife4j.spring.filter.SecurityBasicAuthFilter.doFilter(SecurityBasicAuthFilter.java:87)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.sf.aom.platform.filter.LogFilter.doFilterInternal(LogFilter.java:102)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:124)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:151)
	at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:81)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	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-05-24 14:43:00.447 aom-platform-[,] [http-nio-9991-exec-9] ERROR o.a.c.c.C.[Tomcat].[localhost][175] - Exception Processing ErrorPage[errorCode=0, location=/error]
java.lang.NoSuchMethodError: javax.servlet.http.HttpServletRequest.getHttpServletMapping()Ljavax/servlet/http/HttpServletMapping;
	at org.apache.catalina.core.ApplicationHttpRequest.setRequest(ApplicationHttpRequest.java:709)
	at org.apache.catalina.core.ApplicationHttpRequest.<init>(ApplicationHttpRequest.java:115)
	at org.apache.catalina.core.ApplicationDispatcher.wrapRequest(ApplicationDispatcher.java:911)
	at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:358)
	at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312)
	at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:394)
	at org.apache.catalina.core.StandardHostValve.status(StandardHostValve.java:253)
	at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:348)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:173)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	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)

这个错误信息又是从哪里报出来的呢，开始debug排查，是在LogFilter（可以参考另一篇博文）的

filterChain.doFilter(request, response);

这一行抛出来的，后面的请求响应日志也没有打印了

一路debug，终于找到了真正的中断的代码

org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor

引起中断的异常时 HttpMessageNotWritableException

protected <T> void writeWithMessageConverters(@Nullable T value, MethodParameter returnType,
			ServletServerHttpRequest inputMessage, ServletServerHttpResponse outputMessage)
			throws IOException, HttpMediaTypeNotAcceptableException, HttpMessageNotWritableException 

		Object outputValue;
		Class<?> valueType;
		Type declaredType;

		if (value instanceof CharSequence) 
			outputValue = value.toString();
			valueType = String.class;
			declaredType = String.class;
		
		else 
			outputValue = value;
			valueType = getReturnValueType(outputValue, returnType);
			declaredType = getGenericType(returnType);
		

		if (isResourceType(value, returnType)) 
			outputMessage.getHeaders().set(HttpHeaders.ACCEPT_RANGES, "bytes");
			if (value != null && inputMessage.getHeaders().getFirst(HttpHeaders.RANGE) != null) 
				Resource resource = (Resource) value;
				try 
					List<HttpRange> httpRanges = inputMessage.getHeaders().getRange();
					outputMessage.getServletResponse().setStatus(HttpStatus.PARTIAL_CONTENT.value());
					outputValue = HttpRange.toResourceRegions(httpRanges, resource);
					valueType = outputValue.getClass();
					declaredType = RESOURCE_REGION_LIST_TYPE;
				
				catch (IllegalArgumentException ex) 
					outputMessage.getHeaders().set(HttpHeaders.CONTENT_RANGE, "bytes */" + resource.contentLength());
					outputMessage.getServletResponse().setStatus(HttpStatus.REQUESTED_RANGE_NOT_SATISFIABLE.value());
				
			
		


		List<MediaType> mediaTypesToUse;

		MediaType contentType = outputMessage.getHeaders().getContentType();
		if (contentType != null && contentType.isConcrete()) 
			mediaTypesToUse = Collections.singletonList(contentType);
		
		else 
			HttpServletRequest request = inputMessage.getServletRequest();
			List<MediaType> requestedMediaTypes = getAcceptableMediaTypes(request);
			List<MediaType> producibleMediaTypes = getProducibleMediaTypes(request, valueType, declaredType);

			if (outputValue != null && producibleMediaTypes.isEmpty()) 
				throw new HttpMessageNotWritableException(
						"No converter found for return value of type: " + valueType);
			
			mediaTypesToUse = new ArrayList<>();
			for (MediaType requestedType : requestedMediaTypes) 
				for (MediaType producibleType : producibleMediaTypes) 
					if (requestedType.isCompatibleWith(producibleType)) 
						mediaTypesToUse.add(getMostSpecificMediaType(requestedType, producibleType));
					
				
			
			if (mediaTypesToUse.isEmpty()) 
				if (outputValue != null) 
					throw new HttpMediaTypeNotAcceptableException(producibleMediaTypes);
				
				return;
			
			MediaType.sortBySpecificityAndQuality(mediaTypesToUse);
		

		MediaType selectedMediaType = null;
		for (MediaType mediaType : mediaTypesToUse) 
			if (mediaType.isConcrete()) 
				selectedMediaType = mediaType;
				break;
			
			else if (mediaType.equals(MediaType.ALL) || mediaType.equals(MEDIA_TYPE_APPLICATION)) 
				selectedMediaType = MediaType.APPLICATION_OCTET_STREAM;
				break;
			
		

		if (selectedMediaType != null) 
			selectedMediaType = selectedMediaType.removeQualityValue();
			for (HttpMessageConverter<?> converter : this.messageConverters) 
				GenericHttpMessageConverter genericConverter = (converter instanceof GenericHttpMessageConverter ?
						(GenericHttpMessageConverter<?>) converter : null);
				if (genericConverter != null ?
						((GenericHttpMessageConverter) converter).canWrite(declaredType, valueType, selectedMediaType) :
						converter.canWrite(valueType, selectedMediaType)) 
					outputValue = getAdvice().beforeBodyWrite(outputValue, returnType, selectedMediaType,
							(Class<? extends HttpMessageConverter<?>>) converter.getClass(),
							inputMessage, outputMessage);
					if (outputValue != null) 
						addContentDispositionHeader(inputMessage, outputMessage);
						if (genericConverter != null) 
							genericConverter.write(outputValue, declaredType, selectedMediaType, outputMessage);
						
						else 
							((HttpMessageConverter) converter).write(outputValue, selectedMediaType, outputMessage);
						
						if (logger.isDebugEnabled()) 
							logger.debug("Written [" + outputValue + "] as \\"" + selectedMediaType +
									"\\" using [" + converter + "]");
						
					
					return;
				
			
		

		if (outputValue != null) 
			throw new HttpMediaTypeNotAcceptableException(this.allSupportedMediaTypes);

度娘HttpMediaTypeNotAcceptableException异常出现的原因是

http请求报头[Request Headers]中的Accept字段，是否与服务器返回的响应报头[Response Headers]的Content-Type是否匹配，如不匹配，则会抛出该错误。
Accept表示浏览器期望请求得到资源类型
Content-Type表示服务器返回资源类型

得到一个有用的信息，是因为Accept请求头引起

浏览器中接口的请求头信息：

Accept:application/octet-stream

Postman中的请求头信息：

Postman默认是*/*，表示所有都接收

这就能解释为啥同一个接口，通过Postman返回正常，而通过浏览器返回不正常，原因仅仅是因为Accept请求头。

原因找到了，该怎么解决

方案1：让前端将导出的接口的Accept请求改成application/json,application/octet-stream（开发测试时使用）

通过charles模拟改写请求头

响应正常

方案2：在nginx上将Accept为application/octet-stream的请求头覆盖城application/json,application/octet-stream或*/*（nginx不允许在if块中使用请求头proxy_set_header）

方案3：在gateway中重写请求头

Consumer<HttpHeaders> httpHeaders = httpHeader -> 
    // 向下游转发accept请求头-处理导出接口，未授权时接口返回json信息
    boolean hasAcceptHeader = exchange.getRequest().getHeaders().getAccept().stream()
            .filter(o -> Objects.equals(o, MediaType.APPLICATION_OCTET_STREAM)).count() > 0;
    if (hasAcceptHeader) 
        httpHeader.setAccept(Lists.newArrayList(MediaType.ALL));
    
;

ServerHttpRequest serverHttpRequest = exchange.getRequest().mutate().headers(httpHeaders).build();
exchange.mutate().request(serverHttpRequest).build();

以上是关于记一次接口授权导致的500异常排查的主要内容，如果未能解决你的问题，请参考以下文章

记一次接口授权导致的500异常排查

记一次 CMS GC导致 FULL GC 时间开销很大的排查