From 5502a76c759a05b1d284a32e6adbbfcb47cbe9a8 Mon Sep 17 00:00:00 2001 From: t-horikawa Date: Wed, 9 Oct 2024 10:08:54 +0900 Subject: [PATCH] implement tpcc response time distribution statistics --- .../tsubakuro/examples/tpcc/Client.java | 12 +- .../tsubakuro/examples/tpcc/Delivery.java | 2 +- .../tsubakuro/examples/tpcc/Main.java | 3 +- .../tsubakuro/examples/tpcc/NewOrder.java | 2 +- .../tsubakuro/examples/tpcc/OrderStatus.java | 2 +- .../tsubakuro/examples/tpcc/Payment.java | 2 +- .../tsubakuro/examples/tpcc/Profile.java | 243 +++++++++++------- .../tsubakuro/examples/tpcc/StockLevel.java | 2 +- 8 files changed, 170 insertions(+), 98 deletions(-) diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Client.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Client.java index 5a3378f..37e6101 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Client.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Client.java @@ -67,7 +67,7 @@ public void run() { wId = (int) delivery.warehouseId(); if (!doingDelivery.getAndSet(wId - 1, true)) { delivery.transaction(stop); - profile.time.delivery += (System.nanoTime() - transactionStart); + profile.addTimeDelivery(System.nanoTime() - transactionStart); doingDelivery.set(wId - 1, false); pendingDelivery--; if (pendingDelivery > 0) { @@ -81,15 +81,15 @@ public void run() { if (transactionType <= Percent.KXCT_NEWORDER_PERCENT) { newOrder.setParams(); newOrder.transaction(stop); - profile.time.newOrder += (System.nanoTime() - transactionStart); + profile.addTimeNewOrder(System.nanoTime() - transactionStart); } else if (transactionType <= Percent.KXCT_PAYMENT_PERCENT) { payment.setParams(); payment.transaction(stop); - profile.time.payment += (System.nanoTime() - transactionStart); + profile.addTimePayment(System.nanoTime() - transactionStart); } else if (transactionType <= Percent.KXCT_ORDERSTATUS_PERCENT) { orderStatus.setParams(); orderStatus.transaction(stop); - profile.time.orderStatus += (System.nanoTime() - transactionStart); + profile.addTimeOrderStatus(System.nanoTime() - transactionStart); } else if (transactionType <= Percent.KXCT_DELIEVERY_PERCENT) { if (pendingDelivery > 0) { pendingDelivery++; @@ -99,7 +99,7 @@ public void run() { wId = (int) delivery.warehouseId(); if (!doingDelivery.getAndSet(wId - 1, true)) { delivery.transaction(stop); - profile.time.delivery += (System.nanoTime() - transactionStart); + profile.addTimeDelivery(System.nanoTime() - transactionStart); doingDelivery.set(wId - 1, false); } else { pendingDelivery++; @@ -107,7 +107,7 @@ public void run() { } else { stockLevel.setParams(); stockLevel.transaction(stop); - profile.time.stockLevel += (System.nanoTime() - transactionStart); + profile.addTimeStockLevel(System.nanoTime() - transactionStart); } } profile.elapsed = System.currentTimeMillis() - start; diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Delivery.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Delivery.java index 8974715..ad54eeb 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Delivery.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Delivery.java @@ -107,7 +107,7 @@ void rollback(Transaction transaction) throws IOException, ServerException, Inte @SuppressWarnings("checkstyle:methodlength") public void transaction(AtomicBoolean stop) throws IOException, ServerException, InterruptedException { - while (!stop.get()) { + while (!stop.get()) { // placed for transaction reexecution due to failure. If the transaction ends normally, it returns. try (var transaction = sqlClient.createTransaction().get();) { profile.invocation.delivery++; long dId; diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Main.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Main.java index 500bd01..c113485 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Main.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Main.java @@ -16,6 +16,7 @@ public final class Main { private static String url = System.getProperty("tsurugi.dbname"); + private static String printDistribution = System.getProperty("printResponseTimeDistribution"); static long warehouses() throws IOException, ServerException, InterruptedException, TimeoutException { try ( @@ -82,7 +83,7 @@ public static void main(String[] args) { AtomicBoolean stop = new AtomicBoolean(); for (int i = 0; i < threads; i++) { - var profile = new Profile(); + var profile = new Profile(printDistribution.equals("") || (printDistribution == "true")); // default true (temporary) profile.warehouses = warehouses; profile.threads = threads; profile.index = i; diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/NewOrder.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/NewOrder.java index c2ad74a..9e437b4 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/NewOrder.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/NewOrder.java @@ -184,7 +184,7 @@ void rollback(Transaction transaction) throws IOException, ServerException, Inte @SuppressWarnings("checkstyle:methodlength") public void transaction(AtomicBoolean stop) throws IOException, ServerException, InterruptedException { - while (!stop.get()) { + while (!stop.get()) { // placed for transaction reexecution due to failure. If the transaction ends normally, it returns. try (var transaction = sqlClient.createTransaction().get();) { profile.invocation.newOrder++; total = 0; diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/OrderStatus.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/OrderStatus.java index ab8a58f..d7d4ac9 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/OrderStatus.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/OrderStatus.java @@ -119,7 +119,7 @@ void rollback(Transaction transaction) throws IOException, ServerException, Inte @SuppressWarnings("checkstyle:methodlength") public void transaction(AtomicBoolean stop) throws IOException, ServerException, InterruptedException { - while (!stop.get()) { + while (!stop.get()) { // placed for transaction reexecution due to failure. If the transaction ends normally, it returns. try (var transaction = sqlClient.createTransaction().get();) { profile.invocation.orderStatus++; if (!paramsByName) { diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Payment.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Payment.java index 78de22b..b8b2763 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Payment.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Payment.java @@ -191,7 +191,7 @@ void rollback(Transaction transaction) throws IOException, ServerException, Inte @SuppressWarnings("checkstyle:methodlength") public void transaction(AtomicBoolean stop) throws IOException, ServerException, InterruptedException { - while (!stop.get()) { + while (!stop.get()) { // placed for transaction reexecution due to failure. If the transaction ends normally, it returns. try (var transaction = sqlClient.createTransaction().get();) { profile.invocation.payment++; diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Profile.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Profile.java index d60aa51..ee071fb 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Profile.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/Profile.java @@ -1,34 +1,75 @@ package com.tsurugidb.tsubakuro.examples.tpcc; public class Profile { - static class Counter { - long newOrder; - long payment; - long orderStatus; - long delivery; - long stockLevel; + static final int MUL = 10; + static final int DIV = 10; + static final int RESPONSE_TIME_DIV = MUL * DIV + 1; - Counter() { - this.newOrder = 0; - this.payment = 0; - this.orderStatus = 0; - this.delivery = 0; - this.stockLevel = 0; - } - void add(Counter counter) { - newOrder += counter.newOrder; - payment += counter.payment; - orderStatus += counter.orderStatus; - delivery += counter.delivery; - stockLevel += counter.stockLevel; + static class ResponseTimeDistribution { + private String name; + private long[] counters = new long[RESPONSE_TIME_DIV]; + + ResponseTimeDistribution(String name) { + this.name = name; + } + void add(ResponseTimeDistribution result) { + for (int i = 0; i < RESPONSE_TIME_DIV; i++) { + counters[i] += result.counters[i]; + } + } + void put(long t) { + counters[index(t)]++; + } + private int index(long t) { // ns -> ms + int i = (int) ((t - 500000) / 1000000); + if (i < 0) { + return 0; + } + if (i >= RESPONSE_TIME_DIV) { + return RESPONSE_TIME_DIV - 1; + } + return i; + } + void print() { + System.out.printf("response time distribution for %s transaction%n", name); + for (int i = 0; i < MUL; i++) { + System.out.printf("%3d-%3d(ms):", i * DIV + 1, (i + 1) * DIV); + for (int j = 0; j < DIV; j++) { + int idx = i * DIV + j; + System.out.printf(" %6d", counters[idx]); + } + System.out.printf("%n"); + } + System.out.printf("%3d(ms)- : %6d", DIV * MUL + 1, counters[RESPONSE_TIME_DIV - 1]); + } } + static class Counter { + long newOrder; + long payment; + long orderStatus; + long delivery; + long stockLevel; + + Counter() { + this.newOrder = 0; + this.payment = 0; + this.orderStatus = 0; + this.delivery = 0; + this.stockLevel = 0; + } + void add(Counter counter) { + newOrder += counter.newOrder; + payment += counter.payment; + orderStatus += counter.orderStatus; + delivery += counter.delivery; + stockLevel += counter.stockLevel; + } } - + public long warehouses; public long threads; public long index; public boolean fixThreadMapping; - public Counter time; public Counter invocation; public Counter completion; public Counter retryOnStatement; @@ -43,80 +84,110 @@ void add(Counter counter) { public long elapsed; public long count; public long inconsistentIndexCount; // for temporary use - + private Counter time; + private ResponseTimeDistribution newOrderDistribution; + private boolean printDistribution; + + public Profile(boolean printDist) { + time = new Counter(); + invocation = new Counter(); + completion = new Counter(); + retryOnStatement = new Counter(); + retryOnCommit = new Counter(); + error = new Counter(); + districtTable = new Counter(); + warehouseTable = new Counter(); + ordersTable = new Counter(); + customerTable = new Counter(); + stockTable = new Counter(); + newOrderDistribution = new ResponseTimeDistribution("new order"); + newOrderIntentionalRollback = 0; + count = 0; + printDistribution = printDist; + inconsistentIndexCount = 0; // for temporary use + } public Profile() { - time = new Counter(); - invocation = new Counter(); - completion = new Counter(); - retryOnStatement = new Counter(); - retryOnCommit = new Counter(); - error = new Counter(); - districtTable = new Counter(); - warehouseTable = new Counter(); - ordersTable = new Counter(); - customerTable = new Counter(); - stockTable = new Counter(); - newOrderIntentionalRollback = 0; - count = 0; - inconsistentIndexCount = 0; // for temporary use + this(false); } public void add(Profile profile) { - time.add(profile.time); - invocation.add(profile.invocation); - completion.add(profile.completion); - retryOnStatement.add(profile.retryOnStatement); - retryOnCommit.add(profile.retryOnCommit); - error.add(profile.error); - districtTable.add(profile.districtTable); - warehouseTable.add(profile.warehouseTable); - ordersTable.add(profile.ordersTable); - customerTable.add(profile.customerTable); - stockTable.add(profile.stockTable); - newOrderIntentionalRollback += profile.newOrderIntentionalRollback; - elapsed += profile.elapsed; - count++; - inconsistentIndexCount += profile.inconsistentIndexCount; // for temporary use + time.add(profile.time); + invocation.add(profile.invocation); + completion.add(profile.completion); + retryOnStatement.add(profile.retryOnStatement); + retryOnCommit.add(profile.retryOnCommit); + error.add(profile.error); + districtTable.add(profile.districtTable); + warehouseTable.add(profile.warehouseTable); + ordersTable.add(profile.ordersTable); + customerTable.add(profile.customerTable); + stockTable.add(profile.stockTable); + newOrderDistribution.add(profile.newOrderDistribution); + newOrderIntentionalRollback += profile.newOrderIntentionalRollback; + elapsed += profile.elapsed; + count++; + inconsistentIndexCount += profile.inconsistentIndexCount; // for temporary use + printDistribution |= profile.printDistribution; } long ns2us(long t) { - return (t + 500) / 1000; + return (t + 500) / 1000; } long div(long a, long b) { - if (b == 0) { - return a; + if (b == 0) { + return a; + } + return a / b; } - return a / b; + void addTimeNewOrder(long t) { + time.newOrder += t; + newOrderDistribution.put(t); } - public void print(int n) { - if (inconsistentIndexCount > 0) { // for temporary use - System.out.printf("retry due to inconsistent_index: %d times%n%n", inconsistentIndexCount); + void addTimePayment(long t) { + time.payment += t; + } + void addTimeOrderStatus(long t) { + time.orderStatus += t; } - System.out.printf("duration(mS): %d%n", elapsed / count); - System.out.println("==============================================================================================="); - System.out.printf(" new order: %12d / %8d = %6d (us)%n", ns2us(time.newOrder), completion.newOrder + newOrderIntentionalRollback, ns2us(div(time.newOrder , (completion.newOrder + newOrderIntentionalRollback)))); - System.out.printf(" payment: %12d / %8d = %6d (us)%n", ns2us(time.payment), completion.payment, ns2us(div(time.payment, completion.payment))); - System.out.printf("order status: %12d / %8d = %6d (us)%n", ns2us(time.orderStatus), completion.orderStatus, ns2us(div(time.orderStatus, completion.orderStatus))); - System.out.printf(" delivery: %12d / %8d = %6d (us)%n", ns2us(time.delivery), completion.delivery, ns2us(div(time.delivery, completion.delivery))); - System.out.printf(" stock level: %12d / %8d = %6d (us)%n", ns2us(time.stockLevel), completion.stockLevel, ns2us(div(time.stockLevel, completion.stockLevel))); - System.out.println("==============================================================================================="); - System.out.println(" tx type: invocation:completion(:intentional rollback) - retry on statement:retry on commit"); - System.out.println("-----------------------------------------------------------------------------------------------"); - System.out.printf(" new order: %8d:%8d:%8d - %8d:%8d%n", invocation.newOrder, completion.newOrder, newOrderIntentionalRollback, retryOnStatement.newOrder, retryOnCommit.newOrder); - System.out.printf(" payment: %8d:%8d - %8d:%8d%n", invocation.payment, completion.payment, retryOnStatement.payment, retryOnCommit.payment); - System.out.printf("order status: %8d:%8d - %8d:%8d%n", invocation.orderStatus, completion.orderStatus, retryOnStatement.orderStatus, retryOnCommit.orderStatus); - System.out.printf(" delivery: %8d:%8d - %8d:%8d%n", invocation.delivery, completion.delivery, retryOnStatement.delivery, retryOnCommit.delivery); - System.out.printf(" stock level: %8d:%8d - %8d:%8d%n", invocation.stockLevel, completion.stockLevel, retryOnStatement.stockLevel, retryOnCommit.stockLevel); - System.out.println("-----------------------------------------------------------------------------------------------"); - System.out.printf(" new order: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", - ordersTable.newOrder, districtTable.newOrder, warehouseTable.newOrder, customerTable.newOrder, stockTable.newOrder); - System.out.printf(" payment: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", - ordersTable.payment, districtTable.payment, warehouseTable.payment, customerTable.payment, stockTable.payment); - System.out.printf("order status: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", - ordersTable.orderStatus, districtTable.orderStatus, warehouseTable.orderStatus, customerTable.orderStatus, stockTable.orderStatus); - System.out.printf(" delivery: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", - ordersTable.delivery, districtTable.delivery, warehouseTable.delivery, customerTable.delivery, stockTable.delivery); - System.out.printf(" stock level: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", - ordersTable.stockLevel, districtTable.stockLevel, warehouseTable.stockLevel, customerTable.stockLevel, stockTable.stockLevel); - System.out.println("-----------------------------------------------------------------------------------------------"); - System.out.printf("##NoTPM=%.2f%n", ((double) completion.newOrder * 60.0 * 1000.0) / ((double) elapsed / (double) n)); + void addTimeDelivery(long t) { + time.delivery += t; + } + void addTimeStockLevel(long t) { + time.stockLevel += t; + } + public void print(int n) { + if (inconsistentIndexCount > 0) { // for temporary use + System.out.printf("retry due to inconsistent_index: %d times%n%n", inconsistentIndexCount); + } + System.out.printf("duration(mS): %d%n", elapsed / count); + System.out.println("==============================================================================================="); + System.out.printf(" new order: %12d / %8d = %6d (us)%n", ns2us(time.newOrder), completion.newOrder + newOrderIntentionalRollback, ns2us(div(time.newOrder , (completion.newOrder + newOrderIntentionalRollback)))); + System.out.printf(" payment: %12d / %8d = %6d (us)%n", ns2us(time.payment), completion.payment, ns2us(div(time.payment, completion.payment))); + System.out.printf("order status: %12d / %8d = %6d (us)%n", ns2us(time.orderStatus), completion.orderStatus, ns2us(div(time.orderStatus, completion.orderStatus))); + System.out.printf(" delivery: %12d / %8d = %6d (us)%n", ns2us(time.delivery), completion.delivery, ns2us(div(time.delivery, completion.delivery))); + System.out.printf(" stock level: %12d / %8d = %6d (us)%n", ns2us(time.stockLevel), completion.stockLevel, ns2us(div(time.stockLevel, completion.stockLevel))); + System.out.println("==============================================================================================="); + System.out.println(" tx type: invocation:completion(:intentional rollback) - retry on statement:retry on commit"); + System.out.println("-----------------------------------------------------------------------------------------------"); + System.out.printf(" new order: %8d:%8d:%8d - %8d:%8d%n", invocation.newOrder, completion.newOrder, newOrderIntentionalRollback, retryOnStatement.newOrder, retryOnCommit.newOrder); + System.out.printf(" payment: %8d:%8d - %8d:%8d%n", invocation.payment, completion.payment, retryOnStatement.payment, retryOnCommit.payment); + System.out.printf("order status: %8d:%8d - %8d:%8d%n", invocation.orderStatus, completion.orderStatus, retryOnStatement.orderStatus, retryOnCommit.orderStatus); + System.out.printf(" delivery: %8d:%8d - %8d:%8d%n", invocation.delivery, completion.delivery, retryOnStatement.delivery, retryOnCommit.delivery); + System.out.printf(" stock level: %8d:%8d - %8d:%8d%n", invocation.stockLevel, completion.stockLevel, retryOnStatement.stockLevel, retryOnCommit.stockLevel); + System.out.println("-----------------------------------------------------------------------------------------------"); + System.out.printf(" new order: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", + ordersTable.newOrder, districtTable.newOrder, warehouseTable.newOrder, customerTable.newOrder, stockTable.newOrder); + System.out.printf(" payment: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", + ordersTable.payment, districtTable.payment, warehouseTable.payment, customerTable.payment, stockTable.payment); + System.out.printf("order status: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", + ordersTable.orderStatus, districtTable.orderStatus, warehouseTable.orderStatus, customerTable.orderStatus, stockTable.orderStatus); + System.out.printf(" delivery: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", + ordersTable.delivery, districtTable.delivery, warehouseTable.delivery, customerTable.delivery, stockTable.delivery); + System.out.printf(" stock level: ORDERS %6d DISTRICT %6d WAREHOUSE %6d CUSTOMER %6d STOCK %6d%n", + ordersTable.stockLevel, districtTable.stockLevel, warehouseTable.stockLevel, customerTable.stockLevel, stockTable.stockLevel); + System.out.println("-----------------------------------------------------------------------------------------------"); + System.out.printf("##NoTPM=%.2f%n", ((double) completion.newOrder * 60.0 * 1000.0) / ((double) elapsed / (double) n)); + if (printDistribution) { + System.out.printf("\n"); + newOrderDistribution.print(); + } } } diff --git a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/StockLevel.java b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/StockLevel.java index 97ccee9..eaecdc1 100644 --- a/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/StockLevel.java +++ b/modules/tpcc/src/main/java/com/tsurugidb/tsubakuro/examples/tpcc/StockLevel.java @@ -68,7 +68,7 @@ void rollback(Transaction transaction) throws IOException, ServerException, Inte } public void transaction(AtomicBoolean stop) throws IOException, ServerException, InterruptedException { - while (!stop.get()) { + while (!stop.get()) { // placed for transaction reexecution due to failure. If the transaction ends normally, it returns. profile.invocation.stockLevel++; try (var transaction = sqlClient.createTransaction().get();) {