1

记录一次非常麻烦的调试 - 可乐加品客

 11 months ago
source link: https://www.cnblogs.com/cola-pink/p/17374929.html
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

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

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

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

问题解决过程

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

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

  1. 首先注意到没有任何报错的过程,于是添加了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());
      }
      
  2. 这样我定位了问题的位置,但是却不清楚问题的原因。我找了一下发现在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、内存溢出问题。

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

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

image-20230427194646413

直接告诉你超内存了,这个解决也很简单粗暴,在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读取异常。

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

  1. 当上一个内存溢出问题解决后,之后就可以进行到【最后读取文件内容,识别其中的数据,将合法数据添加到数据库中】这个过程了,但是在这时报了一个错误:

    image-20230428092042012

    复制出来,免得有想找的小伙伴找不着相关的问题解决办法:

    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语句的赋值上加了一个中括号,这个问题就解决了。

  2. 解决该问题后,程序开始读取每条数据,此时没有任何问题,但是添加到数据库的过程出问题了:

    image-20230428094507462

    图片里面写的很杂,我发一下:

    invalid byte sequence for encoding "UTF8": 0x00  Call getNextException to see other errors in the batch.;
    

    解释一下,大概就是说类型不合法,与sql编码UTF8不一样!这是批量插入时出现的信息。

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

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

    image-20230428094633406上面是数据库的

    image-20230428094704886

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

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

    image-20230428095001361

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

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

    那么给大家参考一下第二种我做的方式:

    byte[] bytes = data.getBytes("UTF-8");
    String softwareName = new String(bytes, "UTF-8");
    

    这样就可以把原来的data转化为utf-8格式的softwareName变量(转两次,保险)

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

碎碎念(非正文)

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

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

从开始说起吧

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

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

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

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

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

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

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

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

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


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK