Serious performance loss

[happyi]

version sharding-jdbc 5.0.0

Feature Request

the Serious performance loss like

2022-04-02 18:17:49.800 -DEBUG [main] { thread:main,datasource:master }-  - [cn.mezeron.cloud.common.core.interceptor.DynamicDataSource:17] 
Hibernate: insert into nx_order (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_Type, actual_paid_amt, appointment_id, backlog_comment, backlog_flag, befstati_by, belong_org_id, brand_type, collection_flag, comments, confirm_date, confirmed_amt, confirmed_by, current_paid_amt, customer_id, daily_closed, deduct_achievement_amt, emp_order_flag, ex_post_flag, exempt_sign, frist_consume_id, gift_amt, image_id, marketing_order_flag, order_num, order_type, order_type_code, org_ac_id, org_id, original_amt, paid_point, payable_amt, print_flag, rating, room_id, source, status, status_code, sub_type, sub_type_code, syncedFlag, unsigned_flag, unsigned_reason, use_amt, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2022-04-02 18:17:50.108 -DEBUG [main] { thread:main,datasource:master }-  - [cn.mezeron.cloud.common.core.interceptor.DynamicDataSource:17] 
Hibernate: insert into nx_order_item (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_amt_got, achievement_amt_remain, after_date, asset_id, backcase_Price, CartId, customer_id, delivery_status, item_desc, discount, giftAmt, gift_qty, instrument_id, order_id, parent_item_id, unit_price, product_id, promotion_group_id, promotionId, promotionLineId, qty, realAmt, real_price, replaced_id, replaced_product_id, return_price, reverse_record_id, shop_expert_name, shopIngredientCost, specType, status, status_code, synced_flag, prod_type, unit_point, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2022-04-02 18:17:50.225 - INFO [main] { 不分库分表耗时：436,orderId:fb1bb9dcd50f4911a5f036ea700480f8 }-  - [ShardingTest:34] 
2022-04-02 18:17:50.225 -DEBUG [main] { thread:main,datasource:sharding }-  - [cn.mezeron.cloud.common.core.interceptor.DynamicDataSource:17] 
Hibernate: insert into nx_order (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_Type, actual_paid_amt, appointment_id, backlog_comment, backlog_flag, befstati_by, belong_org_id, brand_type, collection_flag, comments, confirm_date, confirmed_amt, confirmed_by, current_paid_amt, customer_id, daily_closed, deduct_achievement_amt, emp_order_flag, ex_post_flag, exempt_sign, frist_consume_id, gift_amt, image_id, marketing_order_flag, order_num, order_type, order_type_code, org_ac_id, org_id, original_amt, paid_point, payable_amt, print_flag, rating, room_id, source, status, status_code, sub_type, sub_type_code, syncedFlag, unsigned_flag, unsigned_reason, use_amt, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2022-04-02 18:17:51.425 - INFO [main] { Logic SQL: insert into nx_order (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_Type, actual_paid_amt, appointment_id, backlog_comment, backlog_flag, befstati_by, belong_org_id, brand_type, collection_flag, comments, confirm_date, confirmed_amt, confirmed_by, current_paid_amt, customer_id, daily_closed, deduct_achievement_amt, emp_order_flag, ex_post_flag, exempt_sign, frist_consume_id, gift_amt, image_id, marketing_order_flag, order_num, order_type, order_type_code, org_ac_id, org_id, original_amt, paid_point, payable_amt, print_flag, rating, room_id, source, status, status_code, sub_type, sub_type_code, syncedFlag, unsigned_flag, unsigned_reason, use_amt, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) }-  - [org.apache.shardingsphere.infra.executor.sql.log.SQLLogger:74] 
2022-04-02 18:17:51.426 - INFO [main] { SQLStatement: MySQLInsertStatement(setAssignment=Optional.empty, onDuplicateKeyColumns=Optional.empty) }-  - [org.apache.shardingsphere.infra.executor.sql.log.SQLLogger:74] 
2022-04-02 18:17:51.427 - INFO [main] { Actual SQL: m1 ::: insert into nx_order_s0 (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_Type, actual_paid_amt, appointment_id, backlog_comment, backlog_flag, befstati_by, belong_org_id, brand_type, collection_flag, comments, confirm_date, confirmed_amt, confirmed_by, current_paid_amt, customer_id, daily_closed, deduct_achievement_amt, emp_order_flag, ex_post_flag, exempt_sign, frist_consume_id, gift_amt, image_id, marketing_order_flag, order_num, order_type, order_type_code, org_ac_id, org_id, original_amt, paid_point, payable_amt, print_flag, rating, room_id, source, status, status_code, sub_type, sub_type_code, syncedFlag, unsigned_flag, unsigned_reason, use_amt, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) ::: [ylhmini-test, 1648894670253, ylhmini-test, 1648894670253, 0, 0.0, null, 0.0, null, null, true, null, null, 生美店, true, null, null, 0.0, null, 0.0, 2d0b487e-c477-48ee-97f0-f2b5b9bbe509, false, 0.0, false, null, null, null, 0.0, null, false, 2d0b487e-c477-48ee-97f0-f2b5b9bbe509, 购买, 0, null, null, 0.0, 0.0, 0.0, false, 0, null, 分片测试, null, 0, 门店, 0, false, true, null, 0.0, 206223e0f6624e99bf26b6402ddbc823] }-  - [org.apache.shardingsphere.infra.executor.sql.log.SQLLogger:74] 
2022-04-02 18:17:51.594 -DEBUG [main] { thread:main,datasource:sharding }-  - [cn.mezeron.cloud.common.core.interceptor.DynamicDataSource:17] 
Hibernate: insert into nx_order_item (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_amt_got, achievement_amt_remain, after_date, asset_id, backcase_Price, CartId, customer_id, delivery_status, item_desc, discount, giftAmt, gift_qty, instrument_id, order_id, parent_item_id, unit_price, product_id, promotion_group_id, promotionId, promotionLineId, qty, realAmt, real_price, replaced_id, replaced_product_id, return_price, reverse_record_id, shop_expert_name, shopIngredientCost, specType, status, status_code, synced_flag, prod_type, unit_point, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2022-04-02 18:17:51.605 - INFO [main] { Logic SQL: insert into nx_order_item (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_amt_got, achievement_amt_remain, after_date, asset_id, backcase_Price, CartId, customer_id, delivery_status, item_desc, discount, giftAmt, gift_qty, instrument_id, order_id, parent_item_id, unit_price, product_id, promotion_group_id, promotionId, promotionLineId, qty, realAmt, real_price, replaced_id, replaced_product_id, return_price, reverse_record_id, shop_expert_name, shopIngredientCost, specType, status, status_code, synced_flag, prod_type, unit_point, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) }-  - [org.apache.shardingsphere.infra.executor.sql.log.SQLLogger:74] 
2022-04-02 18:17:51.606 - INFO [main] { SQLStatement: MySQLInsertStatement(setAssignment=Optional.empty, onDuplicateKeyColumns=Optional.empty) }-  - [org.apache.shardingsphere.infra.executor.sql.log.SQLLogger:74] 
2022-04-02 18:17:51.606 - INFO [main] { Actual SQL: m1 ::: insert into nx_order_item_s0 (created_by, created_time, updated_by, updated_time, version, achievement_amt, achievement_amt_got, achievement_amt_remain, after_date, asset_id, backcase_Price, CartId, customer_id, delivery_status, item_desc, discount, giftAmt, gift_qty, instrument_id, order_id, parent_item_id, unit_price, product_id, promotion_group_id, promotionId, promotionLineId, qty, realAmt, real_price, replaced_id, replaced_product_id, return_price, reverse_record_id, shop_expert_name, shopIngredientCost, specType, status, status_code, synced_flag, prod_type, unit_point, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) ::: [ylhmini-test, 1648894671595, ylhmini-test, 1648894671595, 0, 0.0, 0.0, 0.0, null, null, 0.0, null, 2d0b487e-c477-48ee-97f0-f2b5b9bbe509, null, null, 1.0, 0.0, null, null, 206223e0f6624e99bf26b6402ddbc823, null, null, null, null, null, null, null, 0.0, null, null, null, null, null, null, null, null, 新建, 0, false, null, null, 4ce7f4ac0dd04984a5dff3c0a0404be8] }-  - [org.apache.shardingsphere.infra.executor.sql.log.SQLLogger:74] 
2022-04-02 18:17:51.724 - INFO [main] { 分库分表总耗时：1499,orderId:206223e0f6624e99bf26b6402ddbc823 }-  - [ShardingTest:42] 

insert into order and order_item

not sharing time ：436ms sharing time 1499ms。 More than 300% loss in Multiple tests

the shardingColumn is customerId the shardingAlgorithm is HASH_MOD 。 the order and orderItem is bindingTable the code like below

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.MASTER.toString());
        Long startTime = System.currentTimeMillis();
        String orderId = insertOrder();
        log.info("不分库分表耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        DynamicDataSourceHolder.clearDataSource();

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.SHARDING.toString());
        startTime = System.currentTimeMillis();
        orderId = insertOrder();
        log.info("分库分表总耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        DynamicDataSourceHolder.clearDataSource();

private String insertOrder() {
        String customerId = UUID.randomUUID().toString();
        Order order = new Order();
        order.setCustomerId(customerId);
        order.setOrderNumber(order.getCustomerId());
        order.setOrderType("购买");
        order.setSource("分片测试");
        order = orderRepository.save(order);
       OrderItem orderItem = new OrderItem();
        orderItem.setOrderId(order.getId());
        orderItem.setCustomerId(customerId);
        orderItemRepository.save(orderItem);
        return order.getId();
    }

the demo code refer to https://github.com/happyi/sharding-test.git

[terrymanu]

There are 2 necessary information need to to provided:

1. The version of ShardingSphere
2. Did you use Statement or PreparedStatement, if PreparedStatement is used, the 1st time is slow, after 2nd times, the performance issue is better.

[happyi]

There are 2 necessary information need to to provided:

1. The version of ShardingSphere
2. Did you use Statement or PreparedStatement, if PreparedStatement is used, the 1st time is slow, after 2nd times, the performance issue is better.

1. 5.0.0
2. use jpa

[TeslaCN]

Hi @happyi Could you show us how you did the benchmark? If you test the performance by performing only one insert, the result may be inaccurate. https://www.oracle.com/technical-resources/articles/java/architect-benchmarking.html

[happyi]

Hi @happyi Could you show us how you did the benchmark? If you test the performance by performing only one insert, the result may be inaccurate. https://www.oracle.com/technical-resources/articles/java/architect-benchmarking.html

this is a comparison test with the standard jpa 。the datum point is not sharing the code like bellow

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.MASTER.toString());
        Long startTime = System.currentTimeMillis();
        String orderId = insertOrder();
        log.info("不分库分表耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        orderItemRepository.deleteByOrderId(orderId);
        orderRepository.deleteById(orderId);
        DynamicDataSourceHolder.clearDataSource();

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.SHARDING.toString());
        startTime = System.currentTimeMillis();
        orderId = insertOrder();
        log.info("分库分表总耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        DynamicDataSourceHolder.clearDataSource();
        orderItemRepository.deleteByOrderId(orderId);
        orderRepository.deleteById(orderId);

[TeslaCN]

Hi @happyi Could you show us how you did the benchmark? If you test the performance by performing only one insert, the result may be inaccurate. https://www.oracle.com/technical-resources/articles/java/architect-benchmarking.html

this is a comparison test with the standard jpa 。the datum point is not sharing the code like bellow

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.MASTER.toString());
        Long startTime = System.currentTimeMillis();
        String orderId = insertOrder();
        log.info("不分库分表耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        orderItemRepository.deleteByOrderId(orderId);
        orderRepository.deleteById(orderId);
        DynamicDataSourceHolder.clearDataSource();

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.SHARDING.toString());
        startTime = System.currentTimeMillis();
        orderId = insertOrder();
        log.info("分库分表总耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        DynamicDataSourceHolder.clearDataSource();
        orderItemRepository.deleteByOrderId(orderId);
        orderRepository.deleteById(orderId);

The JIT is not considered in your test. The result cannot represent the performance of ShardingSphere.

[happyi]

Hi @happyi Could you show us how you did the benchmark? If you test the performance by performing only one insert, the result may be inaccurate. https://www.oracle.com/technical-resources/articles/java/architect-benchmarking.html

this is a comparison test with the standard jpa 。the datum point is not sharing the code like bellow

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.MASTER.toString());
        Long startTime = System.currentTimeMillis();
        String orderId = insertOrder();
        log.info("不分库分表耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        orderItemRepository.deleteByOrderId(orderId);
        orderRepository.deleteById(orderId);
        DynamicDataSourceHolder.clearDataSource();

        DynamicDataSourceHolder.setDataSource(DataSourceEnum.SHARDING.toString());
        startTime = System.currentTimeMillis();
        orderId = insertOrder();
        log.info("分库分表总耗时：{},orderId:{}", (System.currentTimeMillis() - startTime), orderId);
        DynamicDataSourceHolder.clearDataSource();
        orderItemRepository.deleteByOrderId(orderId);
        orderRepository.deleteById(orderId);

The JIT is not considered in your test. The result cannot represent the performance of ShardingSphere.

bulk testing get the same result

[TeslaCN]

@happyi Could you share your tests and results with us? And we have done many enhancements of performance in 5.1.1, please try it.

[happyi]

@happyi Could you share your tests and results with us?

Can I add a wechat ？

[TeslaCN]

@happyi Could you share your tests and results with us?

Can I add a wechat ？

It is better to discuss things in a public way. But if you have something unable to upload or sensitive, you may send us an Email.

[happyi]

@happyi Could you share your tests and results with us? And we have done many enhancements of performance in 5.1.1, please try it.

the code refer to https://github.com/happyi/sharding-test.git

[TeslaCN]

We have done a lot of performance enhancements in latest version. I'm closing this.