Trying insert in postgres data by batch query in unlogged table by jdbc (spring jdbctemplate)
For 400-800 first batch query executed in 10-20ms
After some time it slowly to 400-500ms on 1 batch
If i reload postgres then speed return to 10-20ms
Table is:
create unlogged table recommendation_jsonb_unlog
(
req_uuid text,
some_id text,
data jsonb
)
in app log get lines:
2024-04-23T23:06:47.861+03:00 INFO 9556 --- [recs-postgres] [pool-4-thread-1] c.e.r.s.i.l.RecommendationServiceUnlog : ca34f50a-9564-4612-a137-c75327d7791f: Chunk 258/418 saved by 421 ms
2024-04-23T23:06:49.141+03:00 INFO 9556 --- [recs-postgres] [pool-4-thread-1] c.e.r.s.i.l.RecommendationServiceUnlog : ca34f50a-9564-4612-a137-c75327d7791f: Chunk 259/418 saved by 427 ms
2024-04-23T23:06:50.432+03:00 INFO 9556 --- [recs-postgres] [pool-4-thread-1] c.e.r.s.i.l.RecommendationServiceUnlog : ca34f50a-9564-4612-a137-c75327d7791f: Chunk 260/418 saved by 419 ms
In jdbc logs i see pause in sunc and bind command (some time):
for example:
2024-04-21T01:06:36.482+03:00 TRACE 20908 --- [recs-postgres] [pool-4-thread-1] o.postgresql.core.v3.QueryExecutorImpl : FE=> Bind ,type=VARCHAR ...)
2024-04-21T01:06:36.482+03:00 TRACE 20908 --- [recs-postgres] [pool-4-thread-1] o.postgresql.core.v3.QueryExecutorImpl : FE=> Describe(portal=null)
2024-04-21T01:06:36.482+03:00 TRACE 20908 --- [recs-postgres] [pool-4-thread-1] o.postgresql.core.v3.QueryExecutorImpl : FE=> Execute(portal=null,limit=1)
2024-04-21T01:06:36.482+03:00 TRACE 20908 --- [recs-postgres] [pool-4-thread-1] o.postgresql.core.v3.QueryExecutorImpl : FE=> Bind,type=VARCHAR ...)
2024-04-21T01:06:36.520+03:00 TRACE 20908 --- [recs-postgres] [pool-4-thread-1] o.postgresql.core.v3.QueryExecutorImpl : FE=> Describe(portal=null)
2024-04-21T01:06:36.520+03:00 TRACE 20908 --- [recs-postgres] [pool-4-thread-1] o.postgresql.core.v3.QueryExecutorImpl : FE=> Execute(portal=null,limit=1)
first bind time lower than 1 ms, sencond 40ms
in postgres logs (enable auto explain):
2024-04-23 20:04:26.667 UTC [114] LOG: duration: 10.593 ms plan:
Query Text: insert into recommendation_jsonb (req_uuid, some_id, data) values ($1, $2, $3::JSONB),($4, $5, $6::JSONB) [and 98 more]
Insert on recommendation_jsonb (cost=0.00..0.40 rows=0 width=0) (actual time=10.589..10.590 rows=0 loops=1)
Buffers: shared hit=174 dirtied=7 written=7
WAL: records=64 bytes=53183
-> Values Scan on "*VALUES*" (cost=0.00..0.40 rows=32 width=96) (actual time=0.006..0.085 rows=32 loops=1)
2024-04-23 20:04:28.015 UTC [114] LOG: duration: 10.276 ms plan:
In postgres some settings added:
ALTER SYSTEM SET synchronous_commit TO 'off';
ALTER SYSTEM SET wal_level TO 'minimal';
ALTER SYSTEM SET max_wal_senders TO '0';
ALTER SYSTEM SET fsync TO 'off';
A few days ago I managed to configure it so that the insertion speed was consistent 20-30 ms. But I lost that config and I can’t understand what the system is up against now
User postgres in docker (on single server), ssd (>300 mb/s for write) 8 gb ram
Question is: Why is insertion slow after 200-300 iteration?