0
点赞
收藏
分享

微信扫一扫

使用 SpringAOP和SpringIOC一个bean调用另一个bean耗时超过1分钟什么情况?获取一次请求流经方法的调用次数和调用耗时


前言描述:

 在一个Service的实现类里面,

声明另一个bean如下:

@Autowired
private NewsProcessingVo2NewsBusVo newsProcessingVo2NewsBusVo;

然后添加日期时长监控:如图所示

使用 SpringAOP和SpringIOC一个bean调用另一个bean耗时超过1分钟什么情况?获取一次请求流经方法的调用次数和调用耗时_SpringIOC调用耗时过长

使用了JDK8版本的监控时长程序:

Instant endTimeMark = Instant.now();
Long period = Duration.between(startTimeMark, endTimeMark).toMillis();
log.error("5--1公开资讯id :【{}】newPushPublishBus--newsProcessingVo2NewsBusVo.transform,耗时{} 毫秒", newsId, period);

调用的方法:

public News2BusDTO transform(TbmNewsProcessing newsProcessing, TbmNewsInfo newsInfo, List<TbmNewsTags> tagList, TbmNewsDupFilter newsDup, Integer opType) {
Instant endTimeMark1 = Instant.now();
Map<String, String> hwDimAreaMap = ContantData.getHwDimAreaMap();
News2BusDTO news2BusDTO = new News2BusDTO();
BeanUtils.copyProperties(newsInfo, news2BusDTO);
news2BusDTO.setId(newsProcessing.getNewsId());
if(StringUtils.isNotBlank(newsInfo.getContentText())){
news2BusDTO.setContentText(newsInfo.getContentText().replace("\n", "\r\n"));
}
Instant endTimeMark2 = Instant.now();
Long period1 = Duration.between(endTimeMark1, endTimeMark2).toMillis();
log.error("5--1----1公开资讯id :【{}】newsProcessingVo2NewsBusVo.transform---copyProperties,耗时{} 毫秒", newsProcessing.getNewsId(), period1);

news2BusDTO.setSubtitle(newsInfo.getSubTitle());
news2BusDTO.setAppIds(JSONObject.parseArray(newsInfo.getAppIds(), Integer.class));
news2BusDTO.setStdNewsId(newsInfo.getParentNewsId());
news2BusDTO.setMediaSourceCode(newsProcessing.getMediaSourceCode());
news2BusDTO.setAuthorOrg(newsInfo.getAuthorOrg());
news2BusDTO.setAuthorOrgCode(newsProcessing.getAuthorOrgCode());
if (newsProcessing.getHandleStatus().equals(HandleProcessing.REMOVED.getType())) {
news2BusDTO.setPublishStatus(PublicProcessing.OFF.getType().intValue());
} else if (newsProcessing.getHandleStatus().equals(HandleProcessing.PUBLISH.getType())) {
news2BusDTO.setPublishStatus(PublicProcessing.PUBLISH.getType().intValue());
}
if (newsInfo.getSrcPublishDate() != null) {
news2BusDTO.setPublishDate(System.currentTimeMillis());
}
news2BusDTO.setSrcPublishDate(DateUtil.toDate(newsInfo.getSrcPublishDate()));
if (opType == null) {
if (newsInfo.getParentNewsId() != null) {
news2BusDTO.setOpType(OpType.PUBLISH.getType());
} else {
news2BusDTO.setOpType(OpType.CREATE.getType());
}
} else {
news2BusDTO.setOpType(opType);
}
Instant endTimeMark3 = Instant.now();
Long period3 = Duration.between(endTimeMark2, endTimeMark3).toMillis();
log.error("5--1---2公开资讯id :【{}】newsProcessingVo2NewsBusVo.transform---直接复制,耗时{} 毫秒", newsProcessing.getNewsId(), period3);

news2BusDTO.setInfoLevel(newsInfo.getLevel());
List<TagInfo> tagInfoList = Lists.newArrayList();
if (CollectionUtils.isNotEmpty(tagList)) {
tagInfoList = getTagInfoList(tagList);
}
Instant endTimeMark4 = Instant.now();
Long period4 = Duration.between(endTimeMark3, endTimeMark4).toMillis();
log.error("5--1----3公开资讯id :【{}】newsProcessingVo2NewsBusVo.transform---getTagInfoList,耗时{} 毫秒", newsProcessing.getNewsId(), period4);

List<Duplicate> dupList = Lists.newArrayList();
if (newsDup != null) {
Duplicate duplicate = new Duplicate();
duplicate.setId(newsDup.getNewsId());
duplicate.setAuditConfirm(Integer.valueOf(newsDup.getDuplicate()));
duplicate.setContentSimilarity(newsDup.getSimilarity());
duplicate.setTitleSimilarity(newsDup.getTitleSimilarity());
dupList.add(duplicate);
}
news2BusDTO.setDuplicates(dupList);
news2BusDTO.setTagInfo(tagInfoList);
Instant endTimeMark5 = Instant.now();
Long period5 = Duration.between(endTimeMark4, endTimeMark5).toMillis();
log.error("5--1----4公开资讯id :【{}】newsProcessingVo2NewsBusVo.transform---dupList,耗时{} 毫秒", newsProcessing.getNewsId(), period5);
List<ClassUnify> newsClass = Lists.newArrayList();
if (newsProcessing.getArea() != null) {
HwDimArea area = hwBusinessService.getAreaById(newsProcessing.getArea());
hwDimAreaMap.get(newsProcessing.getArea());
ClassUnify areaUnify = new ClassUnify();
areaUnify.setBusinessId(area.getId());
areaUnify.setClassName(area.getAreaName());
news2BusDTO.setRegionClass(areaUnify);
}
Instant endTimeMark6 = Instant.now();
Long period6 = Duration.between(endTimeMark5, endTimeMark6).toMillis();
log.error("5--1----5公开资讯id :【{}】newsProcessingVo2NewsBusVo.transform---newsClass,耗时{} 毫秒", newsProcessing.getNewsId(), period6);
Instant startTimeMark = Instant.now();
if (newsProcessing.getForm() != null) {
getTypeClass(newsClass, newsProcessing.getForm());
}
if (newsProcessing.getRangeBase() != null) {
getTypeClass(newsClass, newsProcessing.getRangeBase());
}
if (newsProcessing.getRangePlus() != null) {
getTypeClass(newsClass, newsProcessing.getRangePlus());
}
if (newsProcessing.getFinancial() != null) {
getTypeClass(newsClass, newsProcessing.getFinancial());
}
if (newsProcessing.getFinancialPlus() != null) {
getTypeClass(newsClass, newsProcessing.getFinancialPlus());
}
if (newsProcessing.getTradingMarket() != null) {
getTypeClass(newsClass, newsProcessing.getTradingMarket());
}
Instant endTimeMark7 = Instant.now();
Long period7 = Duration.between(endTimeMark6, endTimeMark7).toMillis();
log.error("5--1----6公开资讯id :【{}】newsProcessingVo2NewsBusVo.transform---getTypeClass,耗时{} 毫秒", newsProcessing.getNewsId(), period7);
news2BusDTO.setNewsClass(newsClass);
news2BusDTO.setDupNewsId(newsInfo.getDupNewsId());
//20201023添加俩个字段
news2BusDTO.setNewsImportance(newsProcessing.getNewsImportance());
news2BusDTO.setSentiment(newsProcessing.getSentiment());
Instant endTimeMark8 = Instant.now();
Long period8 = Duration.between(endTimeMark7, endTimeMark8).toMillis();
Long period9 = Duration.between(endTimeMark1, endTimeMark8).toMillis();
log.error("5--1----7公开资讯id :【{}】newsProcessingVo2NewsBusVo.transform--- ,耗时{} 毫秒", newsProcessing.getNewsId(), period8);
log.error("5--1这里面统计 资讯id :【{}】newsProcessingVo2NewsBusVo.transform---返回数据 ,耗时{} 毫秒", newsProcessing.getNewsId(), period9);
return news2BusDTO;
}

最后展示的监控结果,如下所示,感觉特别震惊!

2020-12-09 13:38:24.221|:当前基准资讯: 1181776897672基准资讯获取的实时公开库查询结果:[]

2020-12-09 13:38:24.954|:1公开资讯id :【1181776897672】勾选重复资讯id基准资讯,耗时0 毫秒

2020-12-09 13:38:25.057|:2公开资讯id :【1181776897672】查询操作1、TbmNewsInfo 2、TbmNewsProcessing 3、TbmNewsTags,耗时103 毫秒

2020-12-09 13:38:25.200|:3公开资讯id :【1181776897672】更新操作-newPublish---> processingDao.update(newsProcessing),耗时143 毫秒

2020-12-09 13:38:25.200|:4公开资讯id :【1181776897672】tranformNewsEditorOperate组装操作,耗时0 毫秒

2020-12-09 13:38:31.193|5--1----1公开资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform---copyProperties,耗时14 毫秒

2020-12-09 13:38:31.194|5--1---2公开资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform---直接复制,耗时1 毫秒

2020-12-09 13:38:31.195|5--1----3公开资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform---getTagInfoList,耗时1 毫秒

2020-12-09 13:38:31.195|:5--1----4公开资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform---dupList,耗时0 毫秒

2020-12-09 13:38:31.195|:5--1----5公开资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform---newsClass,耗时0 毫秒

2020-12-09 13:38:31.328|:5--1----6公开资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform---getTypeClass,耗时133 毫秒

2020-12-09 13:38:31.328|:5--1----7公开资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform--- ,耗时0 毫秒

2020-12-09 13:38:31.328|:5--1这里面统计 资讯id :【1181776897672】newsProcessingVo2NewsBusVo.transform---返回数据 ,耗时149 毫秒
2020-12-09 13:38:31.329|:5--1公开资讯id :【1181776897672】newPushPublishBus--newsProcessingVo2NewsBusVo.transform,耗时6128 毫秒

2020-12-09 13:39:31.399|发送消息错误topic:audit_platform_to_bus详细的资讯id(key):1181776897672

org.apache.kafka.common.errors.TimeoutException: Failed to update metadata after 60000 ms.

2020-12-09 13:39:31.401|:5公开资讯id :【1181776897672】newPushPublishBus 发送kafka,耗时66201 毫秒

2020-12-09 13:39:31.496|:6公开资讯id :【1181776897672】专题操作--,耗时95 毫秒

2020-12-09 13:39:31.509|:7公开资讯id :【1181776897672】saveLog(oldProcessing, operateVo)操作--,耗时13 毫秒


猜测应该是,主要是是bean的声明在另一个工程下面,导致的不能实时注册,外环依旧存在@Round的调用。

解决办法是把另一个bean的方法,迁移到这个类下面,直接调用就可以





举报

相关推荐

0 条评论