2

One of my service takes a long time to execute. Analysis has shown that nextval() calls of a certain sequence take about 5 seconds each. Why is that, and would you have suggestions to improve this? Thank you.

Context

This is a regular Spring 4.2.4 / Hibernate 5.1.0 application, with Postgresql 9.6.3. The slow service saveAndFlushes a new entity, the graph of which implying the inserts of many linked entities (about 60k).

I have wrapped the driver with DriverSpy, so as to print SQL statements to the console. The SQL generated by Hibernate is consistent with the relationship model, and properly batched (size=100). However, there are many calls to the nextval() of the sequence of the id of the linked entity, each of these taking about 5s.

The target table holds about 4 million records.

Detailed info

Sequence info (grabbed from pgAdmin):

  • currentValue = 54225001
  • increment = 1000
  • minimum = 1
  • maximum = 9223372036854775807
  • cache = 1 (I've tried values 1000 and 10000, no visible change)
  • cycled = no

Hibernate info (simplified by merging a MappedSuperClass with the child class):

@Entity
@SequenceGenerator(allocationSize = 1000, name = "generatorName", sequenceName = "sequenceName")
@Table(...)
public class XXX{

    @Id
    @Column(name = "id")
    @GeneratedValue(strategy = GenerationType.SEQUENCE, generator = "generatorName")
    private Long id;

EDIT: structure of the table (and related objects)

CREATE SEQUENCE seq_id_unit_brief
    START WITH 1
    INCREMENT BY 1000
    NO MINVALUE
    NO MAXVALUE
    CACHE 1;

CREATE TABLE unit_brief (
    id bigint NOT NULL,
    ubf_brief_id bigint NOT NULL,
    ubf_unit_id character varying(50) NOT NULL,
    ubf_start_date date NOT NULL,
    ubf_end_date date NOT NULL,
    modified_by character varying(100) NOT NULL,
    modified_time timestamp without time zone NOT NULL
);

ALTER TABLE ONLY unit_brief
    ADD CONSTRAINT pk_unit_brief PRIMARY KEY (id);

CREATE INDEX idx_unit_brief_brief_id ON unit_brief USING btree (ubf_brief_id);

CREATE INDEX idx_unit_brief_end_date ON unit_brief USING btree (ubf_end_date);

CREATE INDEX idx_unit_brief_start_date ON unit_brief USING btree (ubf_start_date);

ALTER TABLE ONLY unit_brief
    ADD CONSTRAINT fk_unit_brief_brief_id FOREIGN KEY (ubf_brief_id) REFERENCES brief(id);
Elegie
  • 340
  • 1
  • 5
  • 16
  • what does your table DDL look like please? – Jeff Watkins Aug 11 '17 at 13:12
  • I suggest writing a quick SELECT statement along the lines of `select nextval('sequenceName')` and see how long that takes. – Bob Jarvis - Слава Україні Aug 11 '17 at 13:14
  • @JeffWatkins just edited the post with the info. – Elegie Aug 11 '17 at 13:30
  • @BobJarvis I was preparing the statement in pgAdmin, then run the nextval there (select nextval ('sequenceName')) - it took between 300ms and 600ms there. I'm not sure what this means - does it suggest an Hibernate / JDBC issue? – Elegie Aug 11 '17 at 13:32
  • are you sure there are 60k linked entities? Also have you enabled logging to ensure what are the queries that are getting fired? – dimitrisli Aug 11 '17 at 13:57
  • @dimitrisli Hello. Yes, I am sure - I have indeed checked the logs, wrapping the regular driver with Log4JDBC, which let me view all the queries (and check that they were properly batched). – Elegie Aug 11 '17 at 14:04
  • It's one of the areas Hibernate can be terribly inefficient. Rather than letting the DB assign sequence values and getting them when it does `insert`s via return generated keys, iirc it likes to call `nextval` its self. That's never going to be fast for 60 thousand calls. But if it's really doing increment 1000, it should only be doing 60 calls, which is not going to make a difference. How sure are you that nextval is the culprit? – Craig Ringer Aug 11 '17 at 15:12
  • @CraigRinger - [if I understand the concepts here correctly](https://www.postgresql.org/docs/9.6/static/sql-createsequence.html) `increment = 1000, start = 1` means that the sequence will return values of 1001, 2001, 3001, 4001, etc. `cache = 1` means it will only reserve a single value from the sequence at a time, while `cache = 1000` means it will reserve 1000 values and will return values from the cache until they're all used; however, if not all the cached values are used in a particular session they're lost. – Bob Jarvis - Слава Україні Aug 12 '17 at 04:32

0 Answers0