Unexpected slowdown after unsuccessful space reclaim about pg_squeeze

[ahouska]

I can't tell much w/o seeing any performance data. Do you say that processing of the table took only about a minute? If it took rather long time, the slow down could be caused by VACUUM because rows deleted while pg_squeeze is processing given table cannot be processed by VACUUM until pg_squeeze is done with that table. Not sure if this could happen in your database.

[jendabenda]

More details on graph:

• green - postgres disk usage
• violet - docker container memory usage - irrelevant
• number 1 - pg_sqeeze worker start its job and finished it at the end of the small peak (at least that's where the xlock timeout occurred - from squeeze.errors - I assume that pq_squeeze stopped working at that point)
• number 2, 3 - pgcompacttable tests - irrelevant

There is a constant postgres db disk size grow indicated by green line as new items are arriving, then around 1 there is a small peak followed by 2 hours slowdown and after that grow rate is normalized.

Do you mean that VACUUM was triggered by pg_squeeze?

[ahouska]

Thanks for the chart. I don't think that VACUUM was triggered by pg_squeeze. What I say is that pg_squeeze makes deleted rows unreachable by VACUUM - in particular the rows deleted while pg_squeeze was processing particular table. So if pg_squeeze fails to process the table, those deleted rows become visible to VACUUM, and thus VACUUM suddenly has additional work to do. The amount of this additional work should be proportional to the time spent by pg_squeeze on the table. However it's still not clear to me how long this period was in your system. Can you please check the "last_task_created" and "last_task_finished" columns of the "tables_internal" table in the "squeeze" schema?

[jendabenda]

ok, thanks.

last_task_created about 1:00
last_task_finished about 20s later

so the period that pg_squeeze was working was about 20s

[ahouska]

One problem I found is that the replication slot is not released immediately if the squeeze_table() function raises ERROR while being called by the background worker. This is because the worker calls the function via process_current_task() function, and that one catches the ERROR in order to write the error message into the squeeze.errors table. Thus the slot is dropped either on the next call of squeeze_table() or when the worker exits. I need to think how to fix this.

However it's still not clear to me how this can slow down the database. If the slot caused VACUUM to be overloaded as I suspected earlier, some time would be needed for rather huge amount of dead tuples to cumulate, however your chart shows that the database slows down immediately.

Besides that, replication slot prevents WAL files from being deleted / archived, so the disk usage would keep increasing if the slot was the problem. However the chart shows the opposite: disk usage almost stops growing for some time. Maybe you have WAL on a different disk whose monitoring is not included in that chart.

In any case, please check if your WAL archiving is not delayed by the replication slot. If it seems to be, please stop or restart the squeeze worker.

[ahouska]

The replication slot leak is now fixed in the master branch. If you've got suitable environment, please test if it happens to fix the performance issue. The fix will be included in the 1.3 release soon.