diff --git a/cf-module-prod-plan/cf-module-prod-plan-biz/src/main/java/com/cf/imes/module/plan/service/orderImport/factory/ProducingOrderImportFactory.java b/cf-module-prod-plan/cf-module-prod-plan-biz/src/main/java/com/cf/imes/module/plan/service/orderImport/factory/ProducingOrderImportFactory.java index 8e776e15d..83eaf926e 100644 --- a/cf-module-prod-plan/cf-module-prod-plan-biz/src/main/java/com/cf/imes/module/plan/service/orderImport/factory/ProducingOrderImportFactory.java +++ b/cf-module-prod-plan/cf-module-prod-plan-biz/src/main/java/com/cf/imes/module/plan/service/orderImport/factory/ProducingOrderImportFactory.java @@ -180,6 +180,23 @@ public class ProducingOrderImportFactory { private List orderComponentDOS = new ArrayList<>(); private List sealEdgeConfigList; + // 板件阶段明细耗时,仅用于一次导入请求内的性能定位。 + private long plateObjectBuildNanos; + private long customPlateNoNanos; + private long plateModelBuildNanos; + private long plateModelJsonNanos; + private long plateRelationBuildNanos; + private long plateBatchNanos; + private long plateModelCompressionNanos; + private long itemBatchNanos; + private long partBatchNanos; + private int plateBatchCount; + private int plateBatchRows; + private int itemBatchCount; + private int itemBatchRows; + private int partBatchCount; + private int partBatchRows; + private static final String PART_CATEGORY_ONE = "封边条"; private static final String PART_CATEGORY_TWO = "五金"; private static final String PART_CATEGORY_THREE = "组件"; @@ -310,14 +327,26 @@ public class ProducingOrderImportFactory { // 解析板件列表 stageStartedAt = System.nanoTime(); analyzeBlockList(producingImportData.getBlocks()); + long platesElapsedNanos = System.nanoTime() - stageStartedAt; logStage("plates", stageStartedAt); + logPlatePerformanceDetail(platesElapsedNanos); log.debug("====================【cad拆单解析板件结束】===================="); log.debug("====================【cad拆单解析配件开始】===================="); // 解析配件列表 + long itemBatchBeforeParts = itemBatchNanos; + long partBatchBeforeParts = partBatchNanos; + int itemRowsBeforeParts = itemBatchRows; + int partRowsBeforeParts = partBatchRows; stageStartedAt = System.nanoTime(); analyzeParts(producingImportData.getParts()); + long partsElapsedNanos = System.nanoTime() - stageStartedAt; logStage("parts", stageStartedAt); + logPartsPerformanceDetail(partsElapsedNanos, + itemBatchNanos - itemBatchBeforeParts, + partBatchNanos - partBatchBeforeParts, + itemBatchRows - itemRowsBeforeParts, + partBatchRows - partRowsBeforeParts); log.debug("====================【cad拆单解析配件结束】===================="); // 部件入库 @@ -328,6 +357,7 @@ public class ProducingOrderImportFactory { stageStartedAt = System.nanoTime(); orderItemBatchInsertWithinThreshold(orderItemDOS, true); logStage("item-insert", stageStartedAt); + logBatchPerformanceSummary(); log.debug("====================【cad拆单全局保存开始】===================="); // 保存数据柜体、加工组 @@ -389,6 +419,72 @@ public class ProducingOrderImportFactory { return (System.nanoTime() - startedAt) / 1_000_000; } + /** + * 输出板件阶段的纯计算和批量写库累计耗时,避免逐板打印日志。 + */ + private void logPlatePerformanceDetail(long platesElapsedNanos) { + long plateBatchWithoutCompression = + Math.max(0L, plateBatchNanos - plateModelCompressionNanos); + long accountedNanos = plateObjectBuildNanos + customPlateNoNanos + + plateModelBuildNanos + plateModelJsonNanos + plateRelationBuildNanos + + plateBatchNanos + itemBatchNanos; + log.info("[producing-import-plate-detail] orderId={} totalMs={} otherMs={} " + + "plateRows={} plateBatches={} " + + "objectBuildMs={} customPlateNoMs={} modelBuildMs={} modelJsonMs={} " + + "relationBuildMs={} modelCompressMs={} plateDbAndBindMs={} " + + "itemBatchMs={} itemBatchRows={} itemBatches={}", + orderId, nanosToMillis(platesElapsedNanos), + nanosToMillis(Math.max(0L, platesElapsedNanos - accountedNanos)), + plateBatchRows, plateBatchCount, + nanosToMillis(plateObjectBuildNanos), + nanosToMillis(customPlateNoNanos), + nanosToMillis(plateModelBuildNanos), + nanosToMillis(plateModelJsonNanos), + nanosToMillis(plateRelationBuildNanos), + nanosToMillis(plateModelCompressionNanos), + nanosToMillis(plateBatchWithoutCompression), + nanosToMillis(itemBatchNanos), itemBatchRows, itemBatchCount); + } + + /** + * 输出配件阶段中纯计算与批量写库的拆分耗时。 + */ + private void logPartsPerformanceDetail(long partsElapsedNanos, + long itemBatchElapsedNanos, + long partBatchElapsedNanos, + int itemRows, + int partRows) { + long computeNanos = Math.max(0L, + partsElapsedNanos - itemBatchElapsedNanos - partBatchElapsedNanos); + log.info("[producing-import-part-detail] orderId={} totalMs={} computeMs={} " + + "itemBatchMs={} itemRows={} partBatchMs={} partRows={}", + orderId, nanosToMillis(partsElapsedNanos), nanosToMillis(computeNanos), + nanosToMillis(itemBatchElapsedNanos), itemRows, + nanosToMillis(partBatchElapsedNanos), partRows); + } + + /** + * 输出本次导入各张明细表的批量写入总量和总耗时。 + */ + private void logBatchPerformanceSummary() { + log.info("[producing-import-batch-summary] orderId={} " + + "plateRows={} plateBatches={} plateBatchMs={} modelCompressMs={} " + + "itemRows={} itemBatches={} itemBatchMs={} " + + "partRows={} partBatches={} partBatchMs={}", + orderId, + plateBatchRows, plateBatchCount, nanosToMillis(plateBatchNanos), + nanosToMillis(plateModelCompressionNanos), + itemBatchRows, itemBatchCount, nanosToMillis(itemBatchNanos), + partBatchRows, partBatchCount, nanosToMillis(partBatchNanos)); + } + + /** + * 将累计纳秒转换为毫秒。 + */ + private long nanosToMillis(long nanos) { + return nanos / 1_000_000; + } + /** * 获取组织封边条对应配置 */ @@ -612,8 +708,10 @@ public class ProducingOrderImportFactory { return; } // 1、构建树 + 生成结构hash + long detailStartedAt = System.nanoTime(); List roots = buildTree(componentGroupReqVOS); + logStage("components-build-tree", detailStartedAt); // 2、查询装配配置 List names = roots.stream() @@ -622,8 +720,10 @@ public class ProducingOrderImportFactory { .toList(); + detailStartedAt = System.nanoTime(); CommonResult> configResult = assemblyConfigApi.getNotProcessAssemblyConfigByPartNameList(names); + logStage("components-config-query", detailStartedAt); if (configResult.isError()) { throw new ServiceException( @@ -632,11 +732,15 @@ public class ProducingOrderImportFactory { } // 3、刷新组件状态 + detailStartedAt = System.nanoTime(); refreshComponentStatus(roots, configResult.getData()); + logStage("components-refresh-status", detailStartedAt); + detailStartedAt = System.nanoTime(); for (OrderComponentTreeCompareVO root : roots) { createAndCacheComponent(root, null, null, 0); } + logStage("components-cache", detailStartedAt); } /** @@ -936,10 +1040,13 @@ public class ProducingOrderImportFactory { return; } // 获取自定义板编号配置 + long detailStartedAt = System.nanoTime(); plateNoGenerateConfigVO = customPlateNoGenerateService.getPlateNoGenerateConfig(orderId); + logStage("plates-custom-no-config", detailStartedAt); // 一次性查询目标订单的全部已有房间,供板件和配件导入共同复用。 // 配件可能位于本次板件数据未包含的房间,因此这里不能只按本次报文房间名查询。 + detailStartedAt = System.nanoTime(); existRoomIdMap = orderBodyMapper.selectMaps( new QueryWrapper() .select("room_name,MIN(room_id) as room_id") @@ -951,6 +1058,7 @@ public class ProducingOrderImportFactory { m -> String.valueOf(m.get(ROOM_NAME_FIELD)), m -> ((Number) m.get("room_id")).longValue() )); + logStage("plates-existing-rooms", detailStartedAt); for (ProducingImportRoomTree room : douleRoomTree) { // 房间名 @@ -1042,6 +1150,7 @@ public class ProducingOrderImportFactory { * @param block */ private void createPlate(OrderBodyDO orderBodyDO, ProducingImportBlock block) { + long objectBuildStartedAt = System.nanoTime(); // 是否异形 Boolean isSpecialShape = block.isSpecialShape(); // 是否侧面造型 @@ -1145,6 +1254,7 @@ public class ProducingOrderImportFactory { plateDO.setUpdater(operatorName); plateDO.setCreateTime(now); plateDO.setUpdateTime(now); + plateObjectBuildNanos += System.nanoTime() - objectBuildStartedAt; //批量保存板件 // 达到板件数量阈值,停止入库,更新全局参数停止后续入库 @@ -1157,22 +1267,33 @@ public class ProducingOrderImportFactory { // 生成自定义板编号 plateDO.setRoomName(orderBodyDO.getRoomName()); plateDO.setBodyName(orderBodyDO.getName()); + long customPlateNoStartedAt = System.nanoTime(); generateCustomPlateNo(plateDO, block.getCustBlockNo()); + customPlateNoNanos += System.nanoTime() - customPlateNoStartedAt; // 更新房间下板件和异形的数量 orderBodyDO.setPlateNum(orderBodyDO.getPlateNum() + 1); orderBodyDO.setUnregularNum(orderBodyDO.getUnregularNum() + BooleanUtil.toInt(isSpecialShape)); // 创建造型数据 + long modelBuildStartedAt = System.nanoTime(); OrderModelDO orderModelDO = createModel(plateDO, block, plateRemark); + plateModelBuildNanos += System.nanoTime() - modelBuildStartedAt; + long modelJsonStartedAt = System.nanoTime(); plateDO.setModelData(JsonUtils.toJsonString(orderModelDO)); + plateModelJsonNanos += System.nanoTime() - modelJsonStartedAt; plateDOS.add(plateDO); blockSerialNoMap.put(block.getSourceBlockItemId(), plateDO.getPlateNo()); orderPlateBatchInsertWithinThreshold(plateDOS, false); // 遍历加工组信息,生成对应的加工组和item + long relationStartedAt = System.nanoTime(); + long itemBatchBefore = itemBatchNanos; analyzeBlockProcessGroup(orderBodyDO, block, plateId); + long relationElapsed = System.nanoTime() - relationStartedAt; + plateRelationBuildNanos += Math.max(0L, + relationElapsed - (itemBatchNanos - itemBatchBefore)); } /** @@ -2268,6 +2389,9 @@ public class ProducingOrderImportFactory { private void orderPlateBatchInsertWithinThreshold(List list, boolean isLast) { // 达到批量的阈值就做一次插入 if (CollUtil.isNotEmpty(list) && (list.size() >= BATCH_THRESHOLD_NUMBER || isLast)) { + int batchRows = list.size(); + long batchStartedAt = System.nanoTime(); + long[] compressionNanos = {0L}; String sql = "INSERT INTO order_plate (id,organ_id,order_id,name,plate_no,type,goods_id,width,height,thickness,split_width,split_height,split_thickness,seal_left,seal_right,seal_up,seal_down,area,texture,hole_face,hole_arrange,unregular_point_count,front_hole_count,back_hole_count,side_hole_count,front_model_count,back_model_count,is_door,open_door_type,offset_x,offset_y,is_arc_across,module_type_id,is_special_shaped,is_sculpt,is_side_sculpt,is_2v,is_side_2v,is_row_hole,is_optimized,is_cutted,filter_type,remark,is_cancel,deleted,custom_plate_no,create_time,update_time,creator,updater, cad_plate_no, model_data, reserved_edge_left, reserved_edge_right, reserved_edge_up, reserved_edge_down, source_block_item_id) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)"; jdbcTemplate.batchUpdate(sql, new BatchPreparedStatementSetter() { /** {@inheritDoc} */ @@ -2328,7 +2452,9 @@ public class ProducingOrderImportFactory { String modelData = item.getModelData(); if (StringUtils.isNotEmpty(modelData)) { + long compressionStartedAt = System.nanoTime(); ps.setString(52, JsonUtils.zipString(modelData)); + compressionNanos[0] += System.nanoTime() - compressionStartedAt; } else { ps.setNull(52, Types.BLOB); } @@ -2345,6 +2471,17 @@ public class ProducingOrderImportFactory { return list.size(); } }); + long batchElapsed = System.nanoTime() - batchStartedAt; + plateBatchNanos += batchElapsed; + plateModelCompressionNanos += compressionNanos[0]; + plateBatchCount++; + plateBatchRows += batchRows; + log.info("[producing-import-batch] orderId={} table=order_plate batch={} rows={} " + + "elapsedMs={} modelCompressMs={} dbAndBindMs={}", + orderId, plateBatchCount, batchRows, + nanosToMillis(batchElapsed), + nanosToMillis(compressionNanos[0]), + nanosToMillis(Math.max(0L, batchElapsed - compressionNanos[0]))); if (!isLast) { @@ -2370,6 +2507,8 @@ public class ProducingOrderImportFactory { private void orderItemBatchInsertWithinThreshold(List list, boolean isLast) { // 达到批量的阈值就做一次插入 if (CollUtil.isNotEmpty(list) && (list.size() >= BATCH_THRESHOLD_NUMBER || isLast)) { + int batchRows = list.size(); + long batchStartedAt = System.nanoTime(); String sql = "INSERT INTO order_item (id,order_id,type,room_id,body_id,package_id,group_id,plate_id,parts_id,num,organ_id,comp_id,cad_view_id,source_parts_item_id) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?)"; jdbcTemplate.batchUpdate(sql, new BatchPreparedStatementSetter() { @@ -2415,6 +2554,12 @@ public class ProducingOrderImportFactory { return list.size(); } }); + long batchElapsed = System.nanoTime() - batchStartedAt; + itemBatchNanos += batchElapsed; + itemBatchCount++; + itemBatchRows += batchRows; + log.info("[producing-import-batch] orderId={} table=order_item batch={} rows={} elapsedMs={}", + orderId, itemBatchCount, batchRows, nanosToMillis(batchElapsed)); if (!isLast) { @@ -2440,6 +2585,8 @@ public class ProducingOrderImportFactory { private void orderPartBatchInsertWithinThreshold(List list, boolean isLast) { // 达到批量的阈值就做一次插入 if (CollUtil.isNotEmpty(list) && (list.size() >= BATCH_THRESHOLD_NUMBER || isLast)) { + int batchRows = list.size(); + long batchStartedAt = System.nanoTime(); String sql = "INSERT INTO order_parts (id,organ_id,order_id,goods_id,name,color,material,category,type,width,length,thickness,model,spec,brand,factory,unit,price,is_composite,subparts,remark,deleted,create_time,update_time,creator,updater) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)"; jdbcTemplate.batchUpdate(sql, new BatchPreparedStatementSetter() { @@ -2481,6 +2628,12 @@ public class ProducingOrderImportFactory { return list.size(); } }); + long batchElapsed = System.nanoTime() - batchStartedAt; + partBatchNanos += batchElapsed; + partBatchCount++; + partBatchRows += batchRows; + log.info("[producing-import-batch] orderId={} table=order_parts batch={} rows={} elapsedMs={}", + orderId, partBatchCount, batchRows, nanosToMillis(batchElapsed)); if (!isLast) {