Impossible amount of Writes - WAL

TimescaleDB and PostgreSQL
1

Hi,
it’s me again. :slight_smile:

We are collecting around 400k values each 5 minutes into a hypertable. The table structure is the usual:

                     Table "public.app_values"
 Column |           Type           | Collation | Nullable | Default 
--------+--------------------------+-----------+----------+---------
 id     | integer                  |           | not null | 
 tstamp | timestamp with time zone |           | not null | 
 name   | smallint                 |           |          | 0
 value  | double precision         |           |          |
Indexes:
    "app_values_id_idx" btree (id)
    "app_values_tstamp_idx" brin (tstamp)

When running iostat I see a constant 7-10MB/s write by postgres, and this just doesn’t add up for me :frowning: and I’m fully stuck with this. Even with the row overhead it should be around 20Mb / 5 mins! Even with indeces this 7-10MB/s constant write is inexplicable for me.

The writes may trigger an update in an other table, but not all of them do. Let’s say 70% does. There we update two timestamps, and two ints. This still doesnt add up for me.

Please give me pointers! I would much appreciate it.

Thank you!
Bests,
Semirke

2

Hi there,

yes, it was the WAL. Maybe it’s just me, but this is insane. I understand the concept of the WAL, it’s not about that. But still.

I checked and the 16MB wal segment was rewritten 10MB/s for 6-8 seconds(!!), I guess again and again (I mean one wal 16MB segment had 80MB write before it was closed). Meanwhile the actual data change (the ingress and updates) is one or tow magnitudes lower than that.

I tried to tweak around the wal and checkpoint settings, but nothing changed this.

Currently I have fsync turned off, that seemed to eased the IO load, but in reality I got spikes now, so maybe the overall write is around the same. – Edit: checked, now we are down to 80MB in roughly 2 mins, which is 0.6MB/s. So what’s happening here? :open_mouth:

These are in the WAL, lots of them:
rmgr: Heap len (rec/tot): 54/ 54, tx: 2151919337, lsn: 1004/A3FFFE20, prev 1004/A3FFFDF8, desc: LOCK off 97: xid 2151919337: flags 0x00 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/40657/41258 blk 4
rmgr: Heap len (rec/tot): 87/ 87, tx: 2151919337, lsn: 1004/A3FFFE58, prev 1004/A3FFFE20, desc: INSERT off 90 flags 0x00, blkref #0: rel 1663/40657/12108043 blk 12857
rmgr: Btree len (rec/tot): 64/ 64, tx: 2151919337, lsn: 1004/A3FFFEB0, prev 1004/A3FFFE58, desc: INSERT_LEAF off 181, blkref #0: rel 1663/40657/12108053 blk 2843
rmgr: Heap len (rec/tot): 54/ 54, tx: 2151919337, lsn: 1004/A3FFFEF0, prev 1004/A3FFFEB0, desc: LOCK off 20: xid 2151919337: flags 0x00 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/40657/41758 blk 4048
rmgr: Heap len (rec/tot): 82/ 82, tx: 2151919337, lsn: 1004/A3FFFF28, prev 1004/A3FFFEF0, desc: HOT_UPDATE off 16 xmax 2151919337 flags 0x60 ; new off 35 xmax 0, blkref #0: rel 1663/40657/12106449 blk 13339
rmgr: Transaction len (rec/tot): 34/ 34, tx: 2151919337, lsn: 1004/A3FFFF80, prev 1004/A3FFFF28, desc: COMMIT 2023-05-04 12:15:56.874429 EDT

And if I understand well, that’s really what’s happening.
What I dont understand why is the WAL file constantly written?
Or what can I do about this?

Thanks!
Bests,
András

3

For the future: Yes, it was WAL and there is no workaround except doing inserts in batches or longer transactions.
Luckily the writer plugin had commit interval (it was disabled cause locking caused trouble) and enabling it again with a shorter interval made everything run smoothly.