Запрос работает намного медленнее с использованием JDBC - PullRequest
Новая
       38

Запрос работает намного медленнее с использованием JDBC

3 голосов
/ 02 ноября 2019

У меня есть два разных запроса, выполнение которых занимает примерно одинаковое время, когда я работаю с Adminer или DBeaver

Запрос один 

select * from state where state_name = 'Florida';

Когда яЗапустите приведенный выше запрос в Adminer, это займет от

0,032 с до 0,058 с

ОБЪЯСНИТЬ АНАЛИЗ 

Seq Scan on state  (cost=0.00..3981.50 rows=1 width=28) (actual time=1.787..15.047 rows=1 loops=1)
  Filter: (state_name = 'Florida'::citext)
  Rows Removed by Filter: 50
Planning Time: 0.486 ms
Execution Time: 15.779 ms

Запрос второй 

select
    property.id as property_id ,
    full_address,
    street_address,
    street.street,
    city.city as city,
    state.state_code as state_code,
    zipcode.zipcode as zipcode
from
    property
inner join street on
    street.id = property.street_id
inner join city on
    city.id = property.city_id
inner join state on
    state.id = property.state_id
inner join zipcode on
    zipcode.id = property.zipcode_id
where
    full_address = '139-Skillman-Ave-Apt-5C-Brooklyn-NY-11211';

Приведенный выше запрос занимает от

0,025 с до 0,048 с

ОБЪЯСНИТЬ АНАЛИЗ 

Nested Loop  (cost=29.82..65.96 rows=1 width=97) (actual time=0.668..0.671 rows=1 loops=1)
  ->  Nested Loop  (cost=29.53..57.65 rows=1 width=107) (actual time=0.617..0.620 rows=1 loops=1)
        ->  Nested Loop  (cost=29.25..49.30 rows=1 width=120) (actual time=0.582..0.585 rows=1 loops=1)
              ->  Nested Loop  (cost=28.97..41.00 rows=1 width=127) (actual time=0.532..0.534 rows=1 loops=1)
                    ->  Bitmap Heap Scan on property  (cost=28.54..32.56 rows=1 width=131) (actual time=0.454..0.456 rows=1 loops=1)
                          Recheck Cond: (full_address = '139-Skillman-Ave-Apt-5C-Brooklyn-NY-11211'::citext)
                          Heap Blocks: exact=1
                          ->  Bitmap Index Scan on property_full_address  (cost=0.00..28.54 rows=1 width=0) (actual time=0.426..0.426 rows=1 loops=1)
                                Index Cond: (full_address = '139-Skillman-Ave-Apt-5C-Brooklyn-NY-11211'::citext)
                    ->  Index Scan using street_pkey on street  (cost=0.42..8.44 rows=1 width=28) (actual time=0.070..0.070 rows=1 loops=1)
                          Index Cond: (id = property.street_id)
              ->  Index Scan using city_id_pk on city  (cost=0.29..8.30 rows=1 width=25) (actual time=0.047..0.047 rows=1 loops=1)
                    Index Cond: (id = property.city_id)
        ->  Index Scan using state_id_pk on state  (cost=0.28..8.32 rows=1 width=19) (actual time=0.032..0.032 rows=1 loops=1)
              Index Cond: (id = property.state_id)
  ->  Index Scan using zipcode_id_pk on zipcode  (cost=0.29..8.30 rows=1 width=22) (actual time=0.048..0.048 rows=1 loops=1)
        Index Cond: (id = property.zipcode_id)
Planning Time: 5.473 ms
Execution Time: 1.601 ms

У меня есть следующие методы, которые используют JDBCTemplate для выполнения тех же запросов.

Запрос один 

public void performanceTest(String str) {
    template.queryForObject(
            "select * from state where state_name = ?",
            new Object[] { str }, (result, rowNum) -> {
                return result.getObject("state_name");
            });

}

время: 140 мс, что составляет 0,14 секунды

Запрос два 

public void performanceTest(String str) {
    template.queryForObject(
            "SELECT property.id AS property_id , full_address, street_address, street.street, city.city as city, state.state_code as state_code, zipcode.zipcode as zipcode FROM property INNER JOIN street ON street.id = property.street_id INNER JOIN city ON city.id = property.city_id INNER JOIN state ON state.id = property.state_id INNER JOIN zipcode ON zipcode.id = property.zipcode_id WHERE full_address = ?",
            new Object[] { str }, (result, rowNum) -> {
                return result.getObject("property_id");
            });

}

Время, необходимое для выполнения описанного выше метода, составляет

время: 828 мс, что0,825 секунды

Я синхронизирую время выполнения метода, используя этот код ниже 

long startTime1 = System.nanoTime();
propertyRepo.performanceTest(address); //or "Florida" depending which query I'm testing
long endTime1 = System.nanoTime();
long duration1 = TimeUnit.MILLISECONDS.convert((endTime1 - startTime1), TimeUnit.NANOSECONDS);
System.out.println("time: " + duration1);

Почему запрос два намного медленнее, когда я запускаю его из JDBC, по сравнению скогда я запускаю его из Adminer? Что я могу сделать, чтобы улучшить производительность для второго запроса?

РЕДАКТИРОВАТЬ:

Я создал два разных PHP-скрипта, содержащих запросы соответственно. Использование PHP занимает столько же времени, поэтому я предполагаю, что это как-то связано с JDBC? Ниже приведен результат работы скриптов PHP. PHP занимает больше времени, чем Java с Query, так как я не использую пул соединений. Но оба запроса занимают примерно одинаковое количество времени. Что-то вызывает задержку с Query два на JDBC.

enter image description here

РЕДАКТИРОВАТЬ:

Когда я запускаюзапрос с использованием подготовленного заявления это медленно. Но это быстро, когда я запускаю это с заявлением. Я сделал EXPLAIN ANALYZE для обоих, используя readyStatement и оператор

prepareStatement объяснять анализ 

Nested Loop  (cost=1.27..315241.91 rows=1 width=97) (actual time=0.091..688.583 rows=1 loops=1)
  ->  Nested Loop  (cost=0.98..315233.61 rows=1 width=107) (actual time=0.079..688.571 rows=1 loops=1)
        ->  Nested Loop  (cost=0.71..315225.26 rows=1 width=120) (actual time=0.069..688.561 rows=1 loops=1)
              ->  Nested Loop  (cost=0.42..315216.95 rows=1 width=127) (actual time=0.057..688.548 rows=1 loops=1)
                    ->  Seq Scan on property  (cost=0.00..315208.51 rows=1 width=131) (actual time=0.032..688.522 rows=1 loops=1)
                          Filter: ((full_address)::text = '139-Skillman-Ave-Apt-5C-Brooklyn-NY-11211'::text)
                          Rows Removed by Filter: 8790
                    ->  Index Scan using street_pkey on street  (cost=0.42..8.44 rows=1 width=28) (actual time=0.019..0.019 rows=1 loops=1)
                          Index Cond: (id = property.street_id)
              ->  Index Scan using city_id_pk on city  (cost=0.29..8.30 rows=1 width=25) (actual time=0.010..0.010 rows=1 loops=1)
                    Index Cond: (id = property.city_id)
        ->  Index Scan using state_id_pk on state  (cost=0.28..8.32 rows=1 width=19) (actual time=0.008..0.008 rows=1 loops=1)
              Index Cond: (id = property.state_id)
  ->  Index Scan using zipcode_id_pk on zipcode  (cost=0.29..8.30 rows=1 width=22) (actual time=0.010..0.010 rows=1 loops=1)
        Index Cond: (id = property.zipcode_id)
Planning Time: 2.400 ms
Execution Time: 688.674 ms

оператор объяснять анализ 

Nested Loop  (cost=29.82..65.96 rows=1 width=97) (actual time=0.232..0.235 rows=1 loops=1)
  ->  Nested Loop  (cost=29.53..57.65 rows=1 width=107) (actual time=0.220..0.223 rows=1 loops=1)
        ->  Nested Loop  (cost=29.25..49.30 rows=1 width=120) (actual time=0.211..0.213 rows=1 loops=1)
              ->  Nested Loop  (cost=28.97..41.00 rows=1 width=127) (actual time=0.198..0.200 rows=1 loops=1)
                    ->  Bitmap Heap Scan on property  (cost=28.54..32.56 rows=1 width=131) (actual time=0.175..0.177 rows=1 loops=1)
                          Recheck Cond: (full_address = '139-Skillman-Ave-Apt-5C-Brooklyn-NY-11211'::citext)
                          Heap Blocks: exact=1
                          ->  Bitmap Index Scan on property_full_address  (cost=0.00..28.54 rows=1 width=0) (actual time=0.162..0.162 rows=1 loops=1)
                                Index Cond: (full_address = '139-Skillman-Ave-Apt-5C-Brooklyn-NY-11211'::citext)
                    ->  Index Scan using street_pkey on street  (cost=0.42..8.44 rows=1 width=28) (actual time=0.017..0.017 rows=1 loops=1)
                          Index Cond: (id = property.street_id)
              ->  Index Scan using city_id_pk on city  (cost=0.29..8.30 rows=1 width=25) (actual time=0.010..0.010 rows=1 loops=1)
                    Index Cond: (id = property.city_id)
        ->  Index Scan using state_id_pk on state  (cost=0.28..8.32 rows=1 width=19) (actual time=0.007..0.007 rows=1 loops=1)
              Index Cond: (id = property.state_id)
  ->  Index Scan using zipcode_id_pk on zipcode  (cost=0.29..8.30 rows=1 width=22) (actual time=0.010..0.010 rows=1 loops=1)
        Index Cond: (id = property.zipcode_id)
Planning Time: 2.442 ms
Execution Time: 0.345 ms

1 Ответ

0 голосов
/ 02 ноября 2019

Это из-за пула соединений, который используется разными клиентами. Вы можете настроить быстрый пул соединений, например HikariC для JDBC, следующим образом: 

public class HikariCPDataSource {

    private static HikariConfig config = new HikariConfig();
    private static HikariDataSource ds;

    static {
        config.setJdbcUrl("jdbc:h2:mem:test");
        config.setUsername("user");
        config.setPassword("password");
        config.addDataSourceProperty("cachePrepStmts", "true");
        config.addDataSourceProperty("prepStmtCacheSize", "250");
        config.addDataSourceProperty("prepStmtCacheSqlLimit", "2048");
        ds = new HikariDataSource(config);
    }

    public static Connection getConnection() throws SQLException {
        return ds.getConnection();
    }

    private HikariCPDataSource(){}
}
...