问题现象
首先用户反映,有数据不一致情况产生,为了查询什么原因导致的数据不一致问题,
扒拉出来日志看了一通,发现有个简单的查询耗时特别长,平时只要几ms返回结果的
确调用了200多s,查了各个服务的日志,发现并没有什么问题,把日志展开了看,发现
有5分钟时间,系统各种超时,各种错误,包括连接数据库超时,连接redis超时,等等
就考虑看一下GC日志,这一看不要紧,发现这5分钟时间GC日志刷了上千条FullGC,如下图所示:
回收前后内存变化不大,基本没回收掉内存,但还在不断的回收,因为使用的CMS内存回收器,超过最大内存的80%时会进行FullGC,所以JVM一直在傻傻的回收内存空间,应用程序几乎暂停。
好了,基本找到为什么会报错了,但是为什么会频繁的FullGC呢,这个问题又困扰了很久
思考可能是内存泄漏,或者是某个远程接口阻塞导致大量请求堆积,查看代码发现,代码中resttemplate设置的超时时间都是60s超时,而整个GC持续了5分钟,如果内存泄漏,内存会一直不回收,最终导致的结果是内存占满,OutOfMemoryError, 但是这个摸不着头脑的FullGC最终把内存回收掉了,所以应该不是内存泄漏导致的。
猜想可能是某个业务占用内存特别大,并且短时间内回收不掉。
查阅了好久的代码以及日志,最终定位到一段图片压缩的代码,原代码如下:
import net.coobird.thumbnailator.Thumbnails;
public class ImageProcessor {
/**
* 压缩图片 bytes -> bytes
* @param imageContent image bytes
* @param size 压缩尺寸
* @return resized bytes
* @throws IOException e
*/
static byte[] resize(byte[] imageContent, int size) throws IOException {
ByteArrayOutputStream out = new ByteArrayOutputStream();
Thumbnails.of(new ByteArrayInputStream(imageContent)).size(size, size).useExifOrientation(true).outputFormat(FileTypeUtil.JPG).toOutputStream(out);
return out.toByteArray();
}
}
最开始以为是ByteArrayOutputStream流没关闭造成的,查看了ByteArrayOutputStream的源码:
/**
* Closing a <tt>ByteArrayOutputStream</tt> has no effect. The methods in
* this class can be called after the stream has been closed without
* generating an <tt>IOException</tt>.
*/
public void close() throws IOException {
}
close方法不做任何的操作,因为这个是纯内存操作的流,没有跟文件系统打交道,这个地方数据量不需要关闭,用完等待垃圾回收就可以了。
既然不是这里的问题,那我对这个方法做个测试吧,使用了如下的方法打印了内存占用情况:
private static void getFreeMemoryPercentage() {
// 虚拟机级内存情况查询
long vmFree = 0;
long vmUse = 0;
long vmTotal = 0;
long vmMax = 0;
int byteToMb = 1024 * 1024;
Runtime rt = Runtime.getRuntime();
vmTotal = rt.totalMemory() / byteToMb;
vmFree = rt.freeMemory() / byteToMb;
vmMax = rt.maxMemory() / byteToMb;
vmUse = vmTotal - vmFree;
System.out.println("JVM内存已用的空间为:" + vmUse + " MB");
System.out.println("JVM内存的空闲空间为:" + vmFree + " MB");
System.out.println("JVM总内存空间为:" + vmTotal + " MB");
System.out.println("JVM总内存空间为:" + vmMax + " MB");
System.out.println("======================================");
// 操作系统级内存情况查询
OperatingSystemMXBean osmxb = (OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
String os = System.getProperty("os.name");
long physicalFree = osmxb.getFreePhysicalMemorySize() / byteToMb;
long physicalTotal = osmxb.getTotalPhysicalMemorySize() / byteToMb;
long physicalUse = physicalTotal - physicalFree;
System.out.println("操作系统的版本:" + os);
System.out.println("操作系统物理内存已用的空间为:" + physicalFree + " MB");
System.out.println("操作系统物理内存的空闲空间为:" + physicalUse + " MB");
System.out.println("操作系统总物理内存:" + physicalTotal + " MB");
// 获得线程总数
ThreadGroup parentThread;
int totalThread = 0;
for (parentThread = Thread.currentThread().getThreadGroup(); parentThread
.getParent() != null; parentThread = parentThread.getParent()) {
totalThread = parentThread.activeCount();
}
System.out.println("获得线程总数:" + totalThread);
}
main方法如下:
public static void main(String[] args) throws IOException {
byte[] b = Files.readAllBytes(Paths.get("C:\\Users\\zhangwb\\Desktop\\微信图片_20200717174522.png"));
getFreeMemoryPercentage();
System.out.println("压缩前大小:" + b.length);
byte[] a = resize(b, 1920);
getFreeMemoryPercentage();
System.out.println("压缩后大小:" + a.length);
}
执行这个方法打印出来的日志如下:
JVM内存已用的空间为:22 MB
JVM内存的空闲空间为:223 MB
JVM总内存空间为:245 MB
JVM总内存空间为:3616 MB
======================================
操作系统的版本:Windows 10
操作系统物理内存已用的空间为:2538 MB
操作系统物理内存的空闲空间为:13730 MB
操作系统总物理内存:16268 MB
获得线程总数:2
压缩前大小:11398750
JVM内存已用的空间为:423 MB
JVM内存的空闲空间为:228 MB
JVM总内存空间为:651 MB
JVM总内存空间为:3616 MB
======================================
操作系统的版本:Windows 10
操作系统物理内存已用的空间为:2640 MB
操作系统物理内存的空闲空间为:13628 MB
操作系统总物理内存:16268 MB
获得线程总数:2
压缩后大小:255408
可以看到读出来的数据内存占用22M,图片压缩后JVM内存飙升到423M,多了将近20倍!!
图片压缩后大小小了不少,但是内存却多了这么多,这个可能是导致内存飙升,并且一直FullGC的真正元凶。
终于找到问题了,那如何解决呢
替换掉图片压缩的方法,改用GraphicsMagick处理图片,修改完之后的代码如下:
import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.math.NumberUtils;
import org.im4java.core.ConvertCmd;
import org.im4java.core.IMOperation;
/**
* @author prague
* @description 使用GraphicsMagick处理图片
*/
@Slf4j
public class GmImageProcessor {
/**
* 临时文件前缀-原始文件
*/
public static final String SOURCE_PREFIX = "imgCut";
/**
* 临时文件前缀-转换文件
*/
public static final String TARGET_PREFIX = "imgCutResult";
/**
* 所有输出文件都指定为JPEG
*/
private static final String TARGET_IMG_SUFFIX = ".jpg";
public static byte[] resize(byte[] imageContent, int size) throws IOException {
Path sourcePath = null;
Path targetPath = null;
try {
sourcePath = loadFile(imageContent);
IMOperation op = new IMOperation();
targetPath = Files.createTempFile(TARGET_PREFIX, TARGET_IMG_SUFFIX);
op.size(size, size);
op.addImage(sourcePath.toAbsolutePath().toString());
op.resize(size, size, ">");
op.p_profile("*");
op.addImage(targetPath.toAbsolutePath().toString());
log.debug("输出文件路径:{}", targetPath);
ConvertCmd convertCmd = new ConvertCmd(true);
convertCmd.run(op);
return Files.readAllBytes(targetPath);
} catch (Exception e) {
log.error("压缩图片异常", e);
} finally {
deleteFile(sourcePath);
deleteFile(targetPath);
}
return null;
}
/**
* 旋转图
*
* @param degree 逆时针
*/
static byte[] rotateImage(byte[] imageContent, int degree) {
Path sourcePath = null;
Path targetPath = null;
try {
sourcePath = loadFile(imageContent);
IMOperation op = new IMOperation();
//2020-07-28 16:13:06 add by gaotx 兼容瑞琪逆时针度数
op.rotate((double) degree);
op.addImage(sourcePath.toAbsolutePath().toString());
targetPath = Files.createTempFile("imgCutResult", TARGET_IMG_SUFFIX);
log.debug("输出文件路径:{}", targetPath);
op.addImage(targetPath.toAbsolutePath().toString());
ConvertCmd cmd = new ConvertCmd(true);
log.debug(op.toString());
cmd.run(op);
return Files.readAllBytes(targetPath);
} catch (Exception e) {
BusiExceptionUtils.marshException(e);
} finally {
deleteFile(sourcePath);
deleteFile(targetPath);
}
return null;
}
/**
* 把一张大图切成多张小图,期间要保持源文件,完成后删除源文件, 每次切图完成后,删除临时目标文件
*/
static byte[] cut(Path sourcePath, int startX, int startY, int endX, int endY, int degree) {
Path outPath = null;
try {
IMOperation op = new IMOperation();
op.addImage(sourcePath.toAbsolutePath().toString());
int width = NumberUtils.max(endX - startX, 0);
int height = NumberUtils.max(endY - startY, 0);
op.crop(width, height, startX, startY);
if (degree != 0) {
//2020-07-28 16:13:06 add by gaotx 兼容瑞琪逆时针度数
op.rotate((double) degree);
}
outPath = Files.createTempFile(TARGET_PREFIX, FileTypeUtil.JPG);
log.debug("输出文件路径:{}", outPath);
op.addImage(outPath.toAbsolutePath().toString());
ConvertCmd convert = new ConvertCmd(true);
log.debug(op.toString());
convert.run(op);
return Files.readAllBytes(outPath);
} catch (Exception e) {
// TODO 处理异常
} finally {
deleteFile(outPath);
}
return null;
}
/**
* bytes -> path
*
* @param imageContent bytes
* @return path
*/
static Path loadFile(byte[] imageContent) {
Path sourcePath = null;
String suffix = "." + bytes(imageContent);
try {
sourcePath = Files.createTempFile(SOURCE_PREFIX, suffix);
log.debug("当前临时文件路径={}", sourcePath);
Files.write(sourcePath, imageContent);
} catch (IOException e) {
log.error(e.getMessage(), e);
}
return sourcePath;
}
/**
* byte数组转换成16进制字符串
*/
public static String bytes(byte[] src) {
StringBuilder stringBuilder = new StringBuilder();
if (src == null || src.length <= 0) {
return null;
}
// 防止调用的时候没有进行截取前几位
if (src.length > 4) {
src = Arrays.copyOfRange(src, 0, 4);
}
for (byte b : src) {
// 以十六进制(基数 16)无符号整数形式返回一个整数参数的字符串表示形式,并转换为大写
String hv = Integer.toHexString(b & 0xFF).toUpperCase();
if (hv.length() < 2) {
stringBuilder.append(0);
}
stringBuilder.append(hv);
}
return getFileType(stringBuilder.toString());
}
/**
* 根据文件路径获取文件头信息,因为根据文件的后缀名识别文件类型并不准确 424D--->BMP (bmp) , FFD8FF--->JPEG (jpg) , 89504E47---> PNG
* (png)
*
* @return 文件头信息
*/
public static String getFileType(String bytes) {
if (bytes != null) {
if (bytes.contains("FFD8FF")) {
return "jpg";
}
if (bytes.contains("89504E47")) {
return "png";
}
if (bytes.contains("424D")) {
return "bmp";
}
if (bytes.contains("25504446")) {
return "pdf";
}
}
return null;
}
/**
* 删除文件
*
* @param imagePath imagePath
*/
static void deleteFile(Path imagePath) {
try {
if (imagePath != null) {
Files.deleteIfExists(imagePath);
}
log.info("临时文件清理成功");
} catch (IOException e) {
log.error(e.getMessage(), e);
}
}
}
windows系统调试需要下载安装http://www.graphicsmagick.org/,linux环境请自行百度,并且在代码中设置path:
convertCmd.setSearchPath(“C:\Program Files\GraphicsMagick-1.3.35-Q16”);
否则调用会报找不到gm文件的异常
ok,我们对同样的图片进行同样大小的压缩,得出内存占用情况如下:
JVM内存已用的空间为:22 MB
JVM内存的空闲空间为:223 MB
JVM总内存空间为:245 MB
JVM总内存空间为:3616 MB
======================================
操作系统的版本:Windows 10
操作系统物理内存已用的空间为:2762 MB
操作系统物理内存的空闲空间为:13506 MB
操作系统总物理内存:16268 MB
获得线程总数:2
压缩前大小:11398750
14:16:10.583 [main] DEBUG com.yonyou.einvoice.common.util.image.GmImageProcessor - 当前临时文件路径=C:\Users\zhangwb\AppData\Local\Temp\imgCut742249801216682093.png
14:16:10.625 [main] DEBUG com.yonyou.einvoice.common.util.image.GmImageProcessor - 输出文件路径:C:\Users\zhangwb\AppData\Local\Temp\imgCutResult2449445347052121528.jpg
14:16:16.003 [main] INFO com.yonyou.einvoice.common.util.image.GmImageProcessor - 临时文件清理成功
14:16:16.004 [main] INFO com.yonyou.einvoice.common.util.image.GmImageProcessor - 临时文件清理成功
JVM内存已用的空间为:29 MB
JVM内存的空闲空间为:216 MB
JVM总内存空间为:245 MB
JVM总内存空间为:3616 MB
======================================
操作系统的版本:Windows 10
操作系统物理内存已用的空间为:2665 MB
操作系统物理内存的空闲空间为:13603 MB
操作系统总物理内存:16268 MB
获得线程总数:2
压缩后大小:209797
可以看出,图片压缩的更小了,JVM内存基本没有占用,堆外内存也基本没占用。
缺点:需要在服务器上安装插件,如果是私有部署比较麻烦,需要安装人员安装插件,否则图片压缩报错。
上线后就没再出现过内存占用暴增的情况了。
思考:你所看到的错误,并不一定是真正的错误,特别是超时的错误,有可能是其它原因导致的应用暂停,比如频繁的FullGC,比如,线程栈出现的死锁等问题。一定要找到真正的问题,并且经过自己验证过的,所有问题都不是凭空产生的,一定是有原因的,可以使用科学的知识解释的。