记录一次非常麻烦的调试

2023-05-05 17:38 由可乐加品客发表于 #后端开发

此次记录一次非常麻烦的调试问题，不是纯知识分享，只是记录这次调试过程引以为戒。

问题简介

这个功能是公司2021年写的老功能，一直都没有更新过代码，这次在导入一个1.03G的大文件进行读取的过程中出问题了。
简单介绍一下这个功能：
公司使用的spring boot框架构建项目，该功能为项目内的一个接口调用功能。该功能首先，通过远程接口下载文件到局域网sftp服务器上；下载完毕后将服务器文件下载到本机指定位置内；最后读取文件内容，识别其中的数据，将合法数据添加到数据库中。
出现的问题：

导出日志时，try...catch字段不产生任何报错，但是实际上没有任何动作。
内存溢出问题。
json读取异常。
待补充。

问题解决过程

1、`try...catch...`字段不产生任何报错的问题。

这个问题属实是最大问题了，也是困扰很久的问题。
起因是这个功能没有任何报错，但是动作只进行到【下载文件到sftp服务器上】，之后的步骤就没出现了。

首先注意到没有任何报错的过程，于是添加了Logger类，对各个步骤添加了logger以便查看输入。

这个处理方式是：

引入logger相关类，之后在操作类中创建Logger对象，格式如下：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class assetSyncForXN {
    private static final Logger logger = LoggerFactory.getLogger(assetSyncForXN.class);
}

在项目模块的application.yml配置中，配置logger的显示权限：

logging:
  level:
    com.***.***: ERROR
# 这里注意一下：level代表等级，代表下面的包能够展示日志log最低的等级。
# 下面的示例语句，左边【com.***.***】代表包名，表示这个包下面的所有的包含类，都有这个的最低展示权限。
# 右边【ERROR】表示【最低】展示权限，从低到高依次为DEBUG<INFO<WARNING<ERROR<CRITICAL，而日志中展示的log，只展示与该权限相同或更高权限的log
# 打个比方：示例中这样写的权限，我们在这个包下面打出来的日志中就只能看见ERROR权限的log和CRITICAL权限的log。

这样我们就可以在每一句加入logger提示，这些提示语可以在日志中显示，就可以看到代码运行到哪一步停下了。

顺带写一下log在java中如何用：

@Autowired
private Environment env;
private static RestTemplate restTemplate = AuthRestTemplate.restTemplate();

//譬如我们写一个连通方法，我们连通指定的url，获取他的实例对象，取其中的联通码数据
public void assetAllSync() {
    String url = env.getProperty("syncAssetXN.allUrl");
    //可以像String一样拼接，这个就是打出一个普通的String
    logger.info("=========url:"+url);
    ResponseEntity<HashMap> result = restTemplate.getForEntity(url, HashMap.class);
    logger.info("=============================");
    //可以用花括号指代一个变量，变量放在后面用逗号隔开，里面存放Object类型的内容
    logger.debug("result:{}",result);
    logger.info("================联通码:{}",result.getStatusCode());
}

这样我定位了问题的位置，但是却不清楚问题的原因。我找了一下发现在try...catch..块上面有问题，于是发现了catch{}部分里面很匪夷所思的写了一个这个catch：
```
catch(Exception e){
    throw new BizIllegalArgumentException("读取文件============"+e.getMessage());
}
```
我这边发现这个【BizIllegalArgumentException】类是公司内部写的一个异常，而这个异常，一是不会在返回值内出现任何报错，二是在日志内没有任何反馈信息，这就是导致看不出来问题的原因，这个只有一个迅速结束进程的功能，所以我扩充了一下：
```
catch(Exception e){
    logger.error("内部错误1:{}",e);
    throw new BizIllegalArgumentException("读取文件============"+e.getMessage());
}
```
这样打印出来了错误，指向问题：

下载至sftp服务器完毕后，将sftp服务器文件下载到本机指定位置内这个过程中，原本传递来的【sftp地址】参数应该是一个文件夹而不是直接定位到文件，结果发现传递过来的参数是一个文件，应该是调用的接口修改过。（这个不是重点，不详细说了）

这导致下载时，其中有一个ChannelSftp.cd(directory)方法的参数是一个文件，这自然会报错，所以我修改了，程序也进行到了下一步。

备注：

这里一定要注意一点，并不是说，这种自己编写的异常一定打不出来日志，而是因为部分框架构建的时候有问题（譬如我们公司的框架构建的时候就有问题。。。），以至于打不出log，正常情况还是可以的。不过为了以防万一，大家还是用我上面说的那个方法打log比较好。

2、内存溢出问题。

这个不是最恶心的问题，但是确实是一个警示，告诉我们程序中不仅要注意时间复杂度，更要注意空间。

这个问题的报错简单粗暴：

直接告诉你超内存了，这个解决也很简单粗暴，在application.yml里面添加一个配置

msdf:
  java:
    options: -Xmx8g
# -Xmx后面的8g就是指给该运行模块分配8g的内存

分配一下内存就可以了，默认的内存分配时很小的（俺不清楚这个默认是多少，有兴趣可以查查），一般只要到达98%的内存分配时就会报这个问题。所以建议给application.yml添加该配置。

当然，我们关注的是原因，总不能遇到这种情况就无脑加内存。

先放上代码：（已知，saveDir是一个文件夹，里面存放了一个1G的txt文件）

File saveDir = new File(env.getProperty("syncAssetXN.savePath"));
if(!saveDir.exists()){//保存文件路径是否存在，不存在重新创建
    saveDir.mkdirs();
}
SftpClientUtil.downloadByDirectory(callerSftpAddress,env.getProperty("syncAssetXN.savePath"),client);
logger.info("===================关闭连接===========");
client.disconnect();
logger.info("==============listFiles.length:{}",saveDir.listFiles().length);
if(saveDir.listFiles().length>0){// 获取到资产信息文件
    logger.info("=============获取到资产信息文件===============");
    for(File f: saveDir.listFiles()){
        String assetJson = "";
        try{
            logger.info("====1====:"+f.getName());
            InputStream is = new FileInputStream(f);
            logger.info("====2====");
            int iAvail = is.available();
            logger.info("======3======");
            byte[] bytes = new byte[iAvail];
            logger.info("======4======");
            is.read(bytes);
            logger.info("======5======");
            assetJson = '[' + new String(bytes) +']';
            logger.info("======close======");
            is.close();
        }catch(Exception e){
            logger.error("内部错误1:{}",e);
            throw new BizIllegalArgumentException("读取文件============"+e.getMessage());
            //                                    e.printStackTrace();

        }
        buildAssetList(assetJson);
        logger.info("close build!");
        f.delete();
    }

}else{
    logger.error("上传文件为空");
    throw new BizIllegalArgumentException("上传文件为空");
}

其实用一个很粗略的计算就能算出来了，变量无论如何都是存在内存中处理的，

首先：saveDir，1g

其次：for循环中有一个f的文件，也是1g

在者：is这个流变量，放入的是f的流，1g

还有：为bytes分配了1g的大小空间

还包括对各种数据的处理什么的，assetJson的大小也是1g，算来已经5g多了，更别说别的了，默认的数据量是怎么都存不了的，就会报这个问题了。

遇到这种情况，

首先是，最好多用更加局部变量，少用更全局的变量，用的变量的存活时间不能过长；
其次变量一定要控制大小，譬如这个bytes的大小，显然不用一下子分配1g，这个bytes也是要添加到assetJson变量里面的，所以就是一个多余的变量，可以做一个循环，将bytes大小每次少分配一点，也尽快清掉bytes，让这个变量反复添加到assetJson中。

3、json读取异常。

讲一下这个问题的发现历史。

当上一个内存溢出问题解决后，之后就可以进行到【最后读取文件内容，识别其中的数据，将合法数据添加到数据库中】这个过程了，但是在这时报了一个错误：
复制出来，免得有想找的小伙伴找不着相关的问题解决办法：
```
com.alibaba.fastjson.JSONException: syntax error, expect [, actual {, pos 0, fieldName null
```
这个问题解释过来就是：json字段在某个位置本来应该是’[‘，实际上是’{‘

出现问题的java代码：
```
JSONArray jsonArray = JSONArray.parseArray(assetJson);
```
当调用这个代码时，parseArray会逐字解析变成jsonArray变量，当解析到本该是中括号符号时，出现的却是花括号，这就出问题了。

如果你的json字段很短，我们可以打开json字段确认一下，但如果你的字段很长，比如我这个1g（编辑器都没办法打开这个文件，打开就会卡死），那怎么确认？

我们可以仔细思考一下json语句的格式，正常的json字段需要读取为一个一个一个对象的话，中间都是通过花括号和逗号分隔开的，而把各个【json对象】合在一起的方式，就是类似于【Map】一样的中括号拉在一块的。所以这个中括号，要不就是在一整个json语句的外部，把整体框住；要不就是在每个json对象内框住一个map。

这个时候，要不就是推测，要不就是和提供数据方确认，这个字段的问题是出现在哪，我这里直接就是推测，大概就是整个json语句没被中括号框住，事实确实是这样，于是我把json语句的赋值上加了一个中括号，这个问题就解决了。
解决该问题后，程序开始读取每条数据，此时没有任何问题，但是添加到数据库的过程出问题了：

图片里面写的很杂，我发一下：
```
invalid byte sequence for encoding "UTF8": 0x00  Call getNextException to see other errors in the batch.;
```
解释一下，大概就是说类型不合法，与sql编码UTF8不一样！这是批量插入时出现的信息。

于是想办法看一下：linux服务器系统的编码和PGSQL的编码一样，都是UTF8。且sql复制到navicat上直接执行，完全没有问题。

苦思冥想许久，我发现为什么复制过去了的数值，前面和后面不一样捏，我们看一下区别：

上面是数据库的

这个上面是报错日志里面的

NUL各位应该懂得都懂，就是UTF8无法解析的字符，大概要不是一些乱码，要不就是一些特殊符号，这是妥妥的数据问题咯，那为什么会出现复制过来就变成空格了的情况捏，我直接查了一下知乎，有位大佬讲了一下原因。

说这么长就是说：复制的时候会根据编码方式修改。那么这个编码方式通过我们复制粘贴到sql的就是修改过的内容，但是通过程序直接传递是没有进行任何修改的。而又因为我们看的报错日志是utf8格式，这说明，这个字段部分数值是不能通过utf8解析的，问题就是出现在这里了。

这种错误如何解决就得看大家了，要不就是从根源上解决，直接找数据提供方的麻烦；要不就是自己在代码上面修改一下对这个字段的数据，可以通过进行一次UTF8的转换将数据的问题信息消掉（我这边就是这么弄的）；也可以直接判断这种问题信息就不要录入了，当然，这个实现起来得看各位的需求。

那么给大家参考一下第二种我做的方式：
```
byte[] bytes = data.getBytes("UTF-8");
String softwareName = new String(bytes, "UTF-8");
```
这样就可以把原来的data转化为utf-8格式的softwareName变量（转两次，保险）

4、备注

打log的时候，如果只是单步log，程序运行一次就不会再运行的，这种没啥问题；但是遇到要遍历大数据的时候里面打log一定要谨慎，我这个txt文件内有158w条数据，打log的时候给遍历过程内添加了log，结果就是运行奇慢，在我现在写这篇文章的时候还在跑，跑了8个小时了！
json判断的时候一定要仔细，譬如我上面说的那些问题，json稍微出现一点问题，这个数据就会影响全局，批量添加这个数据的时候就报错，导致后面的数据添加不了，程序就中断了。所以当大家有这个需求的时候，对json的判断要多上心，前面准备的越足，即使程序运行慢点，但是这比之后多次调试好吧。

碎碎念（非正文）

当写这篇文章的时候，本人还在测试这个功能的运行情况，运行正常确实已经到最后一步了，但是由于log和数据量的问题，以及测试服务器太拉跨导致跑了很久很久还没跑完，所以我还在等待ing。

这个代码是别人写的，我不敢怎么去修改太多逻辑，我只能在判断上面下点功夫，所以我建议如果是改别人的老代码的这种任务就不要去接。

从开始说起吧

这个任务在开始的时候，需求方发了我数据，当然，数据我是打不开的，电脑带不动；然后发了我报错日志，想想三百多M的日志，打倒是打得开就是特别费劲，一点开，好嘛，从当日0点到当时的日志全给我发过来了，更好笑的是，日志里面没有任何相关内容就结束了，所以那个日志我找了半小时没有任何意义。

这个时候我想到打log，琢磨很久，写了一部分log给现场的人员发了更新包。很神奇啊，有的log他就是不显示，只有你把后面的一些问题解决了才会显示（那不提示log我怎么知道是哪里的问题）；有的log玄学，一会显示一会不显示；我最后好不容易定位try..catch里面加了一些log才找着，真的是恶心。

而当我找到问题所在时，我发现需求和我现在发现的问题对不上。需求说的是：东西下载到本地了，但是数据库没数据。我这边发现，根本没有进行到下载到本地的操作就结束了。于是我远程查看现场，发现只是下载到sftp而已。我发现了这个问题就下班了。

下班回家，被组长骂了一顿，说我不管人家的需求，我说我管了，组长说你有什么问题你就说，不能不管（反正就是不听不听）。第二天问了我加班的同事，告诉我那个人打小报告了，说我没处理。唉，我真的没话说。

后来嘛，让需求问数据提供方，是不是数据给的有问题，不问，一直卡着，我只能在我这边和现场处理这个，现场也不配合，一会不知道干啥去了，我有次急了，发现远程的时候桌面没动静；一会又电脑坏了不能弄。反正挺折磨的，来来回回因为现场和需求方耽搁了五天还没处理完这个bug。

后面好不容易能下载到数据了，那边又说，数据量对不上，就出现了我上面说的最后一个问题，也不知道后面还有没有问题，我这一周都耗这了，我昨天半夜还在看数据有没有跑完。

真的，如果有人看到这里，而且有程序员工作的话，我的建议：

如果代码很久没有变动，但是突然出了问题，大概率是数据提供方出现问题，及时丢锅，找数据提供方确认数据格式，内容的变动是否有问题。
如果你的领导无缘无故骂你，一定是有人背后推动，请记住，要不有能耐找到幕后黑手，要不就直接回怼，你明明做了，无缘无故骂你，一概都是有毛病的人。
如果你的需求和现场不配合，群里怼，找领导反应，事情闹大，恶心他们，请记住，都是干活的，都是平等的，没必要好口气，他们不配合就不要惯着。
如果你的需求是你以前就很烦的需求，请尽量不要接他的活。

最后我还是要吐槽，这个提需求的**，需求讲不明白，自己也搞不懂需求本身，打小报告还，跟小学生似的，催又催的急，交接东西又不积极，真恶心到我了，急急急急急急。

热门相关：骑士归来名门天后：重生国民千金重生之至尊千金战神重生之至尊千金