记录Pcap4j使用的一次异常调查和分析

问题

我们的监控工具择维士提供了完整的网络监控,包括但不限于:

1. 网卡级别流量统计
2. 出入流量统计
3. 按协议的出入流量统计
4. 按目标地址和本地地址的出入流量统计
5. 网络异常流量告警
   但是问题是发现最近的协议统计不工作了, 只能看到网卡级别的统计数据了:
   看不到的协议级别统计:(忽略后面是解决过后采集的最新数据)查看系统日志发现有如下错误:

FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|java.lang.ArrayIndexOutOfBoundsException: arr.length: 182, offset: 56, len: -77, arr: 74258a022700ac1f6bf87e430800450000a8b4dd40004006e348b783323e9a531e1544084ad7b88000004408000080183e3a94cc0000eeb50b0c30bb4d773a03c240eb029f69f36e6a38f5c6e42240ca6f72bc1676e3d7e100884c4dd78c5cabe6800a8e76d3eac3f75c15587c6a4da275df776114b80c0d1e5aaa4a2ad268fd3fa0c12f3bbbc723e7114b441891bd3f93ce8944b4acc3b3658418850cd79326358010aaab8eadebf9270f8e6e94af2346bd3de56e6e
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.util.ByteArrays.validateBounds(ByteArrays.java:1078) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.util.ByteArrays.getSubArray(ByteArrays.java:820) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.UnknownTcpOption.(UnknownTcpOption.java:77) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.UnknownTcpOption.newInstance(UnknownTcpOption.java:45) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticTcpOptionFactory.newInstance(StaticTcpOptionFactory.java:174) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticTcpOptionFactory.newInstance(StaticTcpOptionFactory.java:168) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticTcpOptionFactory.newInstance(StaticTcpOptionFactory.java:29) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.TcpPacket$TcpHeader.(TcpPacket.java:675) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.TcpPacket$TcpHeader.(TcpPacket.java:482) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.TcpPacket.(TcpPacket.java:64) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.TcpPacket.newPacket(TcpPacket.java:60) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticIpNumberPacketFactory$4.newInstance(StaticIpNumberPacketFactory.java:83) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.AbstractStaticPacketFactory.newInstance(AbstractStaticPacketFactory.java:46) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.AbstractStaticPacketFactory.newInstance(AbstractStaticPacketFactory.java:23) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.IpV4Packet.(IpV4Packet.java:94) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.IpV4Packet.newPacket(IpV4Packet.java:61) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticEtherTypePacketFactory$1.newInstance(StaticEtherTypePacketFactory.java:37) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticEtherTypePacketFactory.newInstance(StaticEtherTypePacketFactory.java:111) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticEtherTypePacketFactory.newInstance(StaticEtherTypePacketFactory.java:24) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.EthernetPacket.(EthernetPacket.java:102) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.EthernetPacket.newPacket(EthernetPacket.java:61) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.StaticDataLinkTypePacketFactory$1.newInstance(StaticDataLinkTypePacketFactory.java:39) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.AbstractStaticPacketFactory.newInstance(AbstractStaticPacketFactory.java:46) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.packet.factory.AbstractStaticPacketFactory.newInstance(AbstractStaticPacketFactory.java:23) ~[pcap4j-packetfactory-static-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.core.PcapHandle$GotPacketFuncExecutor$1.run(PcapHandle.java:1476) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.core.PcapHandle$SimpleExecutor.execute(PcapHandle.java:1442) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.core.PcapHandle$GotPacketFuncExecutor.got_packet(PcapHandle.java:1470) ~[pcap4j-core-1.7.3.jar:?]
FINEST|12934/0|Service Zoomphant Agent|22-09-05 16:41:36|       at org.pcap4j.core.NativeMappings.pcap_loop(Native Method) ~[pcap4j-core-1.7.3.jar:?]
client_loop: send disconnect: Broken pipe-09-05 16:41:36|       at org.pcap4j.core.PcapHandle.doLoop(PcapHandle.java:907) ~[pcap4j-core-1.7.3.jar:?]
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30

我们采用pcap4j来收集网络相关数据. 原理在Java 抓包实现 - 使用pcap4j + Xpcap这个文章中有讲述.

调查过程

现在拿到了异常堆栈 至少不会无迹可寻. 异常显示是系统越界, 这里面的构造对象UnknownTcpOption 很奇怪, 难道是某个特殊的tcpoption无法支持? 我们使用的pcap4j是1.7.3 (最新是1.8.2)

复现问题

上面的异常中给出了个数组74258a022... 这个很有可能就是当时完整的数据包, 那么我们可能可以通过这个复原出当时的情况: 注意堆栈的最开始构建的数据包对象是EthernetPacket 其实这个很正常也符合TCP/IP分层协议:
将上面的数组转换为方便的byte[]表示
我用的这个网站将hex转为base64方便代码copy:

import org.pcap4j.packet.*;

import java.util.*;

public class MyTest {
    public static void main(String[] args) throws Exception {
        byte [] bs = Base64.getDecoder().decode("dCWKAicArB9r+H5DCABFAACotN1AAEAG40i3gzI+mlMeFUQISte4gAAARAgAAIAYPjqUzAAA7rULDDC7TXc6A8JA6wKfafNuajj1xuQiQMpvcrwWduPX4QCITE3XjFyr5oAKjnbT6sP3XBVYfGpNonXfd2EUuAwNHlqqSirSaP0/oMEvO7vHI+cRS0QYkb0/k86JRLSsw7NlhBiFDNeTJjWAEKqrjq3r+ScPjm6UryNGvT3lbm4=");
        EthernetPacket p = EthernetPacket.newPacket(bs, 0, bs.length);
        System.out.println(p);   
    }
}

1
2
3
4
5
6
7
8
9
10
11
12
13

然后错误被精确还原了.

在1.8.2 pcap4j 错误如下:

arr is empty.
java.lang.IllegalArgumentException: arr is empty.
	at org.pcap4j.util.ByteArrays.validateBounds(ByteArrays.java:953)
	at org.pcap4j.util.ByteArrays.toHexString(ByteArrays.java:771)
	at org.pcap4j.util.ByteArrays.toHexString(ByteArrays.java:760)
	at org.pcap4j.packet.UnknownTcpOption.toString(UnknownTcpOption.java:147)
	at java.base/java.lang.String.valueOf(String.java:2951)
	at java.base/java.lang.StringBuilder.append(StringBuilder.java:168)
	at org.pcap4j.packet.TcpPacket$TcpHeader.buildString(TcpPacket.java:945)
	at org.pcap4j.packet.AbstractPacket$AbstractHeader$4.buildValue(AbstractPacket.java:416)
	at org.pcap4j.packet.AbstractPacket$AbstractHeader$4.buildValue(AbstractPacket.java:413)
	at org.pcap4j.util.LazyValue.getValue(LazyValue.java:41)
	at org.pcap4j.packet.AbstractPacket$AbstractHeader.toString(AbstractPacket.java:530)
	at org.pcap4j.packet.AbstractPacket.buildString(AbstractPacket.java:236)
	at org.pcap4j.packet.AbstractPacket$4.buildValue(AbstractPacket.java:68)
	at org.pcap4j.packet.AbstractPacket$4.buildValue(AbstractPacket.java:65)
	at org.pcap4j.util.LazyValue.getValue(LazyValue.java:41)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17

解决问题

如果能够把上面的数据包用wireshark类似的工具打开解析下 看看到底是不是数据的问题就最好了. (心想应该不会是数据包本身的问题 因为不可能全都有问题)
最终找到了这个网站 可以解析数据包:
找到tcpoption环节:
tcp 格式:

tcp option格式:(这个网上说的少, 我找的rfc: https://www.ietf.org/rfc/rfc793.txt)
在urgen pointer后开始就是option数据. 有2种格式. 1种是1个字节的option类型. 1种是1字节option类型, 1字节option长度和n字节option数据.
那么我们的例子中0xee (238)就是option类型. 这是啥类型呢? 为啥会被分到UnknownTcpOption里面呢?

在这里查看所有的tcpoption类型: url 是保留类型.
应该是0xee 238这个类型不被pcap4j识别导致的失败

解决

看了下pcap4j实现:在这个instantiaters定义了常见的tcp option列表 比如max segement size/ window scale等:
想来它也不可能解析每个tcpoption也没必要这么做, 所以不认识的就丢到UnknownTcpOption里面去了.
这时候我发现一个点上面的异常中, len是负数(-77):

ArrayIndexOutOfBoundsException: arr.length: 182, offset: 56, len: -77,
1

这个很奇怪, len怎么可能是负数呢? 因为已经可以复现问题了. 所以跟了下堆栈, 方向-77就是0xee 只不过一个是byte表示. java的byte只能表达-128到127的数字. 但是这个跟协议明显是不一致的. 协议规定这个len是1个字节(无符号的), 所以会出现有的时候len可能是负值的情况(但是如果你理解为short 那么就是正值范围128-255).
一看果然如此:
问题原因: 这个tcp option的长度超过了127 (byte表示范围变成负数了), 后面又尝试用这样的代码去取值肯定就报错了:
this.data = ByteArrays.getSubArray(rawData, 2 + offset, this.length - 2); }
所以最终解决方式是:我这里提的pr 原来的作者可能没管这个repo了…
这个在pcap4j 1.8.2的上面现象不太一样 但是都会报错. 解决思路也类似.

总结

TCP/IP协议看似复杂,但是实际上设计的是很简单高效的,RFC设计的也很精巧,而且我们只需要从大到小一点点解析就可以很方便的通过pcap4j得到并解析你想要的任何数据.

广告时间
访问我们的主页来获取全方位的网络监测吧.

参考

1. hex to base 64网址
2. fix地址
3. 原issue地址
4. rfc