Re: New statistics for tuning WAL buffer size

On 2020-10-15 19:49, Fujii Masao wrote:
> On 2020/10/13 11:57, Masahiro Ikeda wrote:
>> On 2020-10-06 15:57, Masahiro Ikeda wrote:
>>> 2.  Number of when new WAL file is created and zero-filled.
>>> 
>>> As Fujii-san already commented, I think it's good for tuning.
>>> 
>>>> Just idea; it may be worth exposing the number of when new WAL file 
>>>> is created and zero-filled. This initialization may have impact on 
>>>> the performance of write-heavy workload generating lots of WAL. If 
>>>> this number is reported high, to reduce the number of this 
>>>> initialization, we can tune WAL-related parameters so that more 
>>>> "recycled" WAL files can be hold.
> 
> +1
> 
> But it might be better to track the number of when new WAL file is
> created whether it's zero-filled or not, if file creation and sync 
> itself
> takes time.

OK, I changed to track the number of when new WAL file is created.

>>> 
>>> 
>>> 3.  Number of when to switch the WAL logfile segment.
>>> 
>>> This is similar to 2, but this counts the number of when WAL file is
>>> recylcled too.
>>> I think it's useful for tuning "wal_segment_size"
>>> if the number is high　relative to the startup time, 
>>> "wal_segment_size"
>>> must be bigger.
> 
> You're thinking to count all the WAL file switch? That number is equal
> to the number of WAL files generated since the last reset of 
> pg_stat_wal?

Yes. I think it might be better to count it because I think the ratio in 
which a new WAL file is created is important.
To calculate it, we need the count all the WAL file switch.


>>> 4. Number of when WAL is flushed
>>> 
>>> I think it's useful for tuning "synchronous_commit" and 
>>> "commit_delay"
>>> for query executions.
>>> If the number of WAL is flushed is high, users can know
>>> "synchronous_commit" is useful for the workload.
>>> 
>>> Also, it's useful for tuning "wal_writer_delay" and
>>> "wal_writer_flush_after" for wal writer.
>>> If the number is high, users can change the parameter for 
>>> performance.
>>> 
>>> I think it's better to separate this for backends and wal writer.
> 
> +1

Thanks, I separated the statistics for backends and wal writer.
When checkpointer process flushes the WAL, the statistics for backends 
are counted now.
Although I think its impact is not big, is it better to make statistics 
for checkpointer?


>>> 5.  Wait time when WAL is flushed.
>>> 
>>> This is the accumulated time when wal is flushed.
>>> If the time becomes much higher,　users can detect the possibility of
>>> disk failure.
> 
> This should be tracked, e.g., only when track_io_timing is enabled?
> Otherwise, tracking that may cause performance overhead.

OK,  I changed the implementation.


>>> Since users can see how much flash time occupies of the query 
>>> execution time,
>>> it may lead to query tuning and so on.
>>> 
>>> Since there is the above reason, I think it's better to separate this
>>> for backends and wal writer.
> 
> 
> I'm afraid that this counter for a backend may be a bit confusing. 
> Because
> when the counter indicates small time, we may think that walwriter 
> almost
> write WAL data and a backend doesn't take time to write WAL. But a 
> backend
> may be just waiting for walwriter to write WAL.

Thanks for your comments. I agreed.



Now, the following is the view implemented in the attached patch.
If you have any other comments, please let me know.

```
postgres=# SELECT * FROM pg_stat_wal;
-[ RECORD 1 ]-------+------------------------------
wal_records         | 1000128       # Total number of WAL records 
generated
wal_fpi             | 1             # Total number of WAL full page 
images generated
wal_bytes           | 124013682     #Total amount of WAL bytes generated
wal_buffers_full    | 7952       #Total number of WAL data written to 
the disk because WAL buffers got full
wal_file            | 14   #Total number of WAL file segment created or 
opened a pre-existing one
wal_init_file       | 7  #Total number of WAL file segment created
wal_write_backend   | 7956    #Total number of WAL data written to the 
disk by backends
wal_write_walwriter | 27　　　　　#Total number of WAL data written to the 
disk by walwriter
wal_write_time      | 40    # Total amount of time that has been spent 
in the portion of WAL data was written to disk by backend and walwriter, 
in milliseconds
wal_sync_backend    | 1   # Total number of WAL data synced to the disk 
by backends
wal_sync_walwriter  | 6   #Total number of WAL data synced to the disk 
by walwriter
wal_sync_time       | 0  # Total amount of time that has been spent in 
the portion of WAL data was synced to disk by backend and walwriter, in 
milliseconds
stats_reset         | 2020-10-16 19:41:01.892272+09
```

Regards,
-- 
Masahiro Ikeda
NTT DATA CORPORATION