SpringBoot项目日志出现异常 Invalid character found in method name. HTTP method names must be tokens

最新推荐文章于 2024-08-13 16:45:58 发布

老干妈炒酸奶

最新推荐文章于 2024-08-13 16:45:58 发布

阅读量7.1k

点赞数 21

分类专栏： SpringBoot Java 文章标签： java spring boot http 腾讯云云服务器

本文链接：https://blog.csdn.net/Lao_gan_ma/article/details/121512386

版权

Java 同时被 2 个专栏收录

5 篇文章 0 订阅

订阅专栏

SpringBoot

4 篇文章 0 订阅

订阅专栏

场景：

部署在腾讯云服务器上的SpringBoot项目
检查日志发现从部署上去(6月份)后开始到现在(11月份)，每天都有一条异常，但期间这个项目的接口我没有访问过。很可疑。
同样的异常，出现在我部署的每个项目日志中。

异常如下

2021-11-19 08:04:00.544  INFO 22526 --- [nio-5055-exec-5] o.apache.coyote.http11.Http11Processor   : Error parsing HTTP request header
 Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level.

java.lang.IllegalArgumentException: Invalid character found in method name [0x030x000x000x130x0e0xe00x000x000x000x000x000x010x000x080x000x020x000x000x00...]. HTTP method names must be tokens
        at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:417) ~[tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:261) ~[tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) [tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1707) [tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.46.jar!/:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_291]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_291]
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.46.jar!/:na]
        at java.lang.Thread.run(Thread.java:748) [na:1.8.0_291]

2021-11-21 03:38:04.003  INFO 22526 --- [nio-5055-exec-5] o.apache.coyote.http11.Http11Processor   : Error parsing HTTP request header
 Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level.

java.lang.IllegalArgumentException: Invalid character found in method name [0x030x000x000x130x0e0xe00x000x000x000x000x000x010x000x080x000x020x000x000x00...]. HTTP method names must be tokens
        at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:417) ~[tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:261) ~[tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) [tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1707) [tomcat-embed-core-9.0.46.jar!/:na]
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.46.jar!/:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_291]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_291]
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.46.jar!/:na]
        at java.lang.Thread.run(Thread.java:748) [na:1.8.0_291]

尝试了网上的主流办法，给配置文件加 server.max-http-header-size=8192，没用
用http访问，没必要，因为出现异常期间，我自己并没有向该url发送任何请求。

那么，就可能是网上一堆爬虫扫描各种ip端口，瞎发送请求导致的？
或许可以在项目的拦截器中加点代码，查看请求方的ip和请求内容

尝试解决

1. `IPUtils`

从(HttpServletRequest)请求对象中提取IP
该工具类代码参考了这篇博客 https://www.cnblogs.com/niunafei/p/13596122.html

package com.example.demo.util;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.util.StringUtils;

import javax.servlet.http.HttpServletRequest;
import java.net.InetAddress;
import java.net.UnknownHostException;

/**
 * Ip地址
 *
 * @author niunafei
 * @function
 * @email niunafei0315@163.com
 * @date 2020/9/28  11:23 AM
 */
public class IPUtils {
    private static Logger logger = LoggerFactory.getLogger(IPUtils.class);
    private static final String IP_UTILS_FLAG = ",";
    private static final String UNKNOWN = "unknown";
    private static final String LOCALHOST_IP = "0:0:0:0:0:0:0:1";
    private static final String LOCALHOST_IP1 = "127.0.0.1";

    /**
     * 获取IP地址
     * <p>
     * 使用Nginx等反向代理软件， 则不能通过request.getRemoteAddr()获取IP地址
     * 如果使用了多级反向代理的话，X-Forwarded-For的值并不止一个，而是一串IP地址，X-Forwarded-For中第一个非unknown的有效IP字符串，则为真实IP地址
     */
    public static String getIpAddr(HttpServletRequest request) {
        String ip = null;
        try {
            //以下两个获取在k8s中，将真实的客户端IP，放到了x-Original-Forwarded-For。而将WAF的回源地址放到了 x-Forwarded-For了。
            ip = request.getHeader("X-Original-Forwarded-For");
            if (!StringUtils.hasText(ip) || UNKNOWN.equalsIgnoreCase(ip)) {
                ip = request.getHeader("X-Forwarded-For");
            }
            //获取nginx等代理的ip
            if (!StringUtils.hasText(ip) || UNKNOWN.equalsIgnoreCase(ip)) {
                ip = request.getHeader("x-forwarded-for");
            }
            if (!StringUtils.hasText(ip) || UNKNOWN.equalsIgnoreCase(ip)) {
                ip = request.getHeader("Proxy-Client-IP");
            }
            if (!StringUtils.hasText(ip) || ip.length() == 0 || UNKNOWN.equalsIgnoreCase(ip)) {
                ip = request.getHeader("WL-Proxy-Client-IP");
            }
            if (!StringUtils.hasText(ip) || UNKNOWN.equalsIgnoreCase(ip)) {
                ip = request.getHeader("HTTP_CLIENT_IP");
            }
            if (!StringUtils.hasText(ip) || UNKNOWN.equalsIgnoreCase(ip)) {
                ip = request.getHeader("HTTP_X_FORWARDED_FOR");
            }
            //兼容k8s集群获取ip
            if (!StringUtils.hasText(ip) || UNKNOWN.equalsIgnoreCase(ip)) {
                ip = request.getRemoteAddr();
                if (LOCALHOST_IP1.equalsIgnoreCase(ip) || LOCALHOST_IP.equalsIgnoreCase(ip)) {
                    //根据网卡取本机配置的IP
                    InetAddress iNet = null;
                    try {
                        iNet = InetAddress.getLocalHost();
                    } catch (UnknownHostException e) {
                        logger.error("getClientIp error: {}", e);
                    }
                    ip = iNet.getHostAddress();
                }
            }
        } catch (Exception e) {
            logger.error("IPUtils ERROR ", e);
        }
        //使用代理，则获取第一个IP地址
        if (StringUtils.hasText(ip) && ip.indexOf(IP_UTILS_FLAG) > 0) {
            ip = ip.substring(0, ip.indexOf(IP_UTILS_FLAG));
        }
        return ip;
    }
}

2. 拦截器: `IPInterceptor`

package com.example.demo.Interceptor;

import com.example.demo.util.IPUtils;
import org.joda.time.DateTime;
import org.springframework.stereotype.Component;
import org.springframework.web.servlet.HandlerInterceptor;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.Enumeration;

@Component
public class IPInterceptor implements HandlerInterceptor {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        //IP
        String ip = IPUtils.getIpAddr(request);
        //考虑到如果对方是爬虫的可能，那么请求也许会很多，手动加分割线区分每次请求，后头看日志可以直观些
        System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: ┌"+"──────────────────────────────────────────────────────────────────────────────────────────────");
        System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: │"+"IP: "+ip);
        System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: │"+"URI: "+request.getRequestURI());     // /index/getAll
        System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: │"+"Method: "+request.getMethod());      //GET
        System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: │"+"CharacterEncoding: "+request.getCharacterEncoding());    //UTF-8
        System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: │"+"QueryString: "+request.getQueryString());    //请求中的查询条件 相当于请求参数 如: name=abc
        Enumeration<String> headers = request.getHeaderNames();
        //Header部分
        while (headers.hasMoreElements()){
            String headerName = headers.nextElement();
            String header = request.getHeader(headerName);
            System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: │-"+headerName+": "+header);
        }
        System.out.println("["+new DateTime().toString("yyyy-MM-dd HH:mm:ss")+"]: └"+"──────────────────────────────────────────────────────────────────────────────────────────────");
        //该拦截器仅用于查看请求的信息内容，不做实际的拦截功能，所以直接return true放行
        return true;
    }
}

3. `InterceptorConfig`

package com.example.demo.Interceptor;

import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

@Configuration
public class InterceptorConfig implements WebMvcConfigurer {

    @Autowired
    private IPInterceptor ipInterceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(ipInterceptor).addPathPatterns("/**");    //对所有请求url拦截(拦截器中会正常放行，所以不影响业务功能)
    }
}

拦截器修改就到这里，随后部署到云服务器上，静等他下一次访问。

-------------------- 一晚上过去了… -------------------------

查看结果

注：所有日志中出现的IP均已用错误的IP代替，防止被攻击误伤

正常的访问请求日志

框内部分均为拦截器中读取的请求信息
框内第一行的IP是发送请求方的IP，-host 部分是我的服务器公网ip和端口
框内所有以-开头的均为请求header中的内容
框外部分是正常访问到controller中对应方法后的输出

[2021-11-23 16:56:29]: ┌──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 16:56:29]: │IP: 123.456.78.910
[2021-11-23 16:56:29]: │URI: /file/listAll
[2021-11-23 16:56:29]: │Method: GET
[2021-11-23 16:56:29]: │CharacterEncoding: UTF-8
[2021-11-23 16:56:29]: │QueryString: null
[2021-11-23 16:56:29]: │-host: 111.9.999.99:6710
[2021-11-23 16:56:29]: │-connection: keep-alive
[2021-11-23 16:56:29]: │-accept: */*
[2021-11-23 16:56:29]: │-user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.45 Safari/537.36 Edg/96.0.1054.29
[2021-11-23 16:56:29]: │-referer: http://111.9.999.99:6710/swagger-ui/index.html?configUrl=/v3/api-docs/swagger-config
[2021-11-23 16:56:29]: │-accept-encoding: gzip, deflate
[2021-11-23 16:56:29]: │-accept-language: zh-CN,zh;q=0.9,en;q=0.8,en-GB;q=0.7,en-US;q=0.6
[2021-11-23 16:56:29]: │-cookie: UM_distinctid=17c213426358d6-0cc6ae181c60a8-513c1743-144000-17c21342636523; CNZZDATA1260117451=1760950175-1632801118-%7C1632813182; username-111-9-999-99-6710="2|1:0|10:1635131997|27:username-111-9-999-99-6710|44:ODNmNmRlMmVlYzU5NDE5ZDlhZDM4YTJiOGQ2OTRkNzk=|808589b96f6d510ebc53cd58b6dbb156fb2dc255b85bf4160fd778df1f4a2a53"
[2021-11-23 16:56:29]: └──────────────────────────────────────────────────────────────────────────────────────────────
2021-11-23 16:56:30.044  INFO 15557 --- [nio-5000-exec-1] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:3, serverValue:17}] to localhost:27017
[2021-11-23 16:56:30]: Get all files...

异常日志部分

(仅截取部分)

[2021-11-23 20:00:58]: ┌──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 20:00:58]: │IP: 123.456.78.910
[2021-11-23 20:00:58]: │URI: /
[2021-11-23 20:00:58]: │Method: GET
[2021-11-23 20:00:58]: │CharacterEncoding: UTF-8
[2021-11-23 20:00:58]: │QueryString: null
[2021-11-23 20:00:58]: │-host: 111.9.999.99:6710
[2021-11-23 20:00:58]: └──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 20:00:58]: ┌──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 20:00:58]: │IP: 123.456.78.910
[2021-11-23 20:00:58]: │URI: /error
[2021-11-23 20:00:58]: │Method: GET
[2021-11-23 20:00:58]: │CharacterEncoding: UTF-8
[2021-11-23 20:00:58]: │QueryString: null
[2021-11-23 20:00:58]: │-host: 111.9.999.99:6710
[2021-11-23 20:00:58]: └──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 21:14:16]: ┌──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 21:14:16]: │IP: 162.142.125.59
[2021-11-23 21:14:16]: │URI: /
[2021-11-23 21:14:16]: │Method: GET
[2021-11-23 21:14:16]: │CharacterEncoding: UTF-8
[2021-11-23 21:14:16]: │QueryString: null
[2021-11-23 21:14:16]: │-host: 111.9.999.99:6710
[2021-11-23 21:14:16]: │-user-agent: Mozilla/5.0 (compatible; CensysInspect/1.1; +https://about.censys.io/)
[2021-11-23 21:14:16]: │-accept: */*
[2021-11-23 21:14:16]: │-accept-encoding: gzip
[2021-11-23 21:14:16]: └──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 21:14:16]: ┌──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 21:14:16]: │IP: 162.142.125.59
[2021-11-23 21:14:16]: │URI: /error
[2021-11-23 21:14:16]: │Method: GET
[2021-11-23 21:14:16]: │CharacterEncoding: UTF-8
[2021-11-23 21:14:16]: │QueryString: null
[2021-11-23 21:14:16]: │-host: 111.9.999.99:6710
[2021-11-23 21:14:16]: │-user-agent: Mozilla/5.0 (compatible; CensysInspect/1.1; +https://about.censys.io/)
[2021-11-23 21:14:16]: │-accept: */*
[2021-11-23 21:14:16]: │-accept-encoding: gzip
[2021-11-23 21:14:16]: └──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 23:50:19]: ┌──────────────────────────────────────────────────────────────────────────────────────────────
[2021-11-23 23:50:19]: │IP: 1.66.666.66
[2021-11-23 23:50:19]: │URI: /
[2021-11-23 23:50:19]: │Method: GET
[2021-11-23 23:50:19]: │CharacterEncoding: UTF-8
[2021-11-23 23:50:19]: │QueryString: null
[2021-11-23 23:50:19]: │-host: 111.9.999.99:6710
[2021-11-23 23:50:19]: │-user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:47.0) Gecko/20100101 Firefox/47.0
[2021-11-23 23:50:19]: │-accept: */*
[2021-11-23 23:50:19]: │-connection: keep-alive
[2021-11-23 23:50:19]: └──────────────────────────────────────────────────────────────────────────────────────────────

分析

对比正常访问和异常访问的日志，可以发现:
- 异常的访问请求这边，几乎没有header(只有一个host用来指定我的服务器公网ip和端口)
- 异常请求均未访问到我的接口(因为框外没有输出，而且uri和我的接口也没有对上)
11-23日17:00部署，截至11-24日 11:00，统计到:
- 访问的uri只有这3个： /，/error，/robots.txt
- 8个IP发送过异常请求
- 异常请求(被拦截器捕获到的)次数：28次
user-agent 表示请求的客户端工具，通常是各类浏览器，这个很多爬虫程序都会设置。
其中有一个IP请求的user-agent比较特殊 user-agent: Mozilla/5.0 (compatible; CensysInspect/1.1; +https://about.censys.io/)
顺藤摸瓜查了下，发现censys是美国的一家公司，专门扫描获取互联网上公开的IP。

以下内容来自Censys公司官网描述（由必应翻译）

Censys 找到可公开访问设备的一种方法是使用互联网范围的扫描。我们每天都会对全球每个IPv4地址进行少量无害的连接尝试。当我们发现计算机或设备配置为接受连接时，我们会通过完成协议握手来跟进，以了解有关正在运行的服务的更多信息。
…
我们从不试图绕过任何技术障碍，利用安全问题或以其他方式访问非面向公众的服务，并且我们遵循社区最佳实践来减轻远程网络的任何负担。我们收到的唯一数据是连接到特定地址和端口的任何人公开可见的信息。
…
有关 Censys 收集的数据类型的技术信息，请访问我们的数据定义页面。
…
Censys 从 192.35.168.0/23、162.142.125.0/24、167.248.133.0/24、167.94.138.0/24、167.94.145.0/24 和 167.94.146.0/24 子网扫描互联网，如果您愿意，可以列出白名单或黑名单。
…
我们有时会通过动态 IP 地址从其他计算机进行后续连接，但阻止上述地址足以防止您的设备出现在我们的 IPv4 数据集中。
…
研究人员和网络管理员有时会使用 Censys 数据来检测安全问题，并向易受攻击的系统向操作员发出警报。如果您阻止我们的扫描，您可能不会收到这些重要的安全通知。

总的来说，那几个访问了/robots.txt的ip还是有良心的，知道看看robots.txt君子协议。
最后收集了其余那7个IP，查了下归属地

归属地
浙江省嘉兴市电信
美国亚利桑那凤凰城
芬兰
美国亚利桑那凤凰城
浙江省嘉兴市电信
美国新泽西纽瓦克 Linode
美国伊利诺斯芝加哥

基本都是国外的，还有俩嘉兴的，其实不管是国外的还是这个嘉兴的，多半都是用了代理，肯定不是他们自己的真实IP。
无奈不太懂爬虫，没法继续深挖下去了。
回头改改robots.txt规则，再写点拦截器拦一下试试，目前来看，这些异常至少不会影响业务，请求并发量也不大。
大家如果有更好的办法，欢迎讨论交流哈，毕竟这些异常虽然没啥影响，但看着确实难受…