1

We are writing a new app against an existing database. I'm using Spring Data JPA, and simply doing a

MyRepository.save() 

on my new entity, using

MyRepository extends CrudRepository<MyThing, String>

I've noticed in the logs that hibernate is doing a Select before the insert, and that they are taking a long time, even when the queries use the primary key or an index. I posted a question earlier asking how to stop the SELECT before the insert. Haven't figured that out. Now I'm just trying to figure out why it's taking so long.

I have the logging set so I can see the sql that hibernate has generated. In one example, according to the logging timing, that query takes about 4 seconds. This one is querying with a primary key. When I run the sql that hibernate generated in a db tool like dbvisualizer, it returns in sub-second, as I would expect.

I increased the hibernate packaging logging to TRACE level, to try to see where the delay is, and found the following, before and after the 4 second delay:

2017-08-11 13:45:40.099 TRACE 16136 --- [nio-8085-exec-1] o.h.l.p.e.i.AbstractLoadPlanBasedLoader  : Bound [2] parameters total
2017-08-11 13:45:44.023 TRACE 16136 --- [nio-8085-exec-1] o.h.r.j.i.ResourceRegistryStandardImpl   : Registering result set [SQLServerResultSet:6]

I'm also wondering why it says 2 parameters bound, when there was only 1 in the sql.

Any ideas why these selects are taking so long? Especially only in my spring app, and not in another client like dbvisualizer?

EDIT: adding more detail, sql, entity code

Note that this example is simply looking up an existing entity; this is not one of the tables where we're doing an insert, and Hibernate is doing the extra SELECT before INSERT, but seems like the delay is the same. This one takes 4 seconds.

Here is the generated sql:

select customer0_.customer_id as customer1_4_0_, customer0_.first_name as first_na2_4_0_, customer0_.last_name as last_nam3_4_0_ from my_customer_table customer0_ where customer0_.customer_id=?

Here is the entity:

import javax.persistence.Entity;
import javax.persistence.Id;
import javax.persistence.Table;

@Entity
@Table(name = "my_customer_table")
public class Customer {

    @Id
    private String customer_id;
    private String first_name;
    private String last_name;

    protected Customer() {}


    public Customer(String firstName, String lastName) {
        this.first_name = firstName;
        this.last_name = lastName;
    }

    @Override
    public String toString() {
        return String.format(
                "Customer[id=%s, firstName='%s', lastName='%s']",
                customer_id, first_name, last_name);
    }
}

Here's the CustomerRepository

import com.....Customer;
import org.springframework.data.repository.CrudRepository;

public interface CustomerRepository extends CrudRepository<Customer, String> {
}

and the code to look up a Customer, from a @Service class where CustomerRepository is @Autowired in:

Customer customer = customerRepository.findOne(customerId);
user26270
  • 6,904
  • 13
  • 62
  • 94
  • You probably need to track down exactly what SQL statement is getting executed before you can understand the performance. This information may be easier to obtain from your DB than via application logging. – Rob Aug 11 '17 at 20:17
  • try to use [log4jdbc](https://stackoverflow.com/q/45346905)... – Cepr0 Aug 12 '17 at 15:49
  • can you please post some code where you are saving your entities!!?? I believe there is an improper iteration somewhere in your code. – Abdullah Khan Aug 14 '17 at 06:32
  • I've added the generated sql and code for entities, repository, service call – user26270 Aug 14 '17 at 14:19
  • wheres the `Select` statement before the `save()` method. Can you please post both of these calls and perhaps the code block itself. The bug is somewhere in there. – Abdullah Khan Aug 14 '17 at 14:25
  • I added a simpler example, but with the same performance problem. Why is this simple query by a primary key taking 4 seconds? – user26270 Aug 14 '17 at 14:32

0 Answers0