PostgreSQL 12 Improvement: Benign Log Entries “Incomplete Startup Packet”

PostgreSQLThere is a less-talked-about improvement in PostgreSQL 12 which can greatly reduce the benign log entries. This patch is probably one of the smallest in PostgreSQL 12.

The commit message says:

This patch is going to improve the experience of many enterprise users by reducing unwanted log entries. It is very common to see the PostgreSQL log file running into several GBs due mainly to such unwanted benign entries.

You can read the full discussion thread at postgresql.org.

Background

In PostgreSQL, for each client connection request to Postmaster (listens on port 5432 by default), a backend process will be created. It then processes the startup packet from the client. Refer to src/backend/postmaster/postmaster.c for the source code. Each client connection request is expected to send a startup message to the PostgreSQL server, and this information in the startup packet is used for setting up the backend process. But there are many more things happening when we deploy PostgreSQL in a datacenter. There could be different monitoring solutions, security scanners, port scanners, HA Solutions, etc hitting on PostgreSQL Port 5432. PostgreSQL starts processing these incoming connections for establishing a client-server communication channel. But many of these tools may have a different intention and won’t be participating in a good client-server protocol.  Historically, PostgreSQL generates a log entry for each of these suspected/bad hits. This can result in log files growing to a huge size and can cause unwanted log-related IO.

Even though it looks silly, this was so annoying that many tool vendors started documenting it for their customers, advising them to just ignore such messages, as we can see here. HA Solutions like Stolon reported a similar problem. Monitoring plugins for Nagios, Cacti, and Zabbix also caused the same, and it appeared in the PostgreSQL mailing list multiple times over several years. For example:

Reproducing the Case

Any port scanner or TCP Port checker can cause the log entries. The ncat/nc utility has Zero-I/O mode and reports connection status only (-z option).

This produces LOG entries like the following for PostgreSQL version up to 11:

But in PostgreSQL 12, it detects that it is zero size packets and just ignores it. There won’t be any entry in the log file.

Additional Note

Unfortunately, some of the tools are not gentle enough to write a zero size packet. As per consciences in the community, this needs to be logged.

Tom Lane explained in the mailing list:

So we should expect to see such messages in PostgreSQL 12 also. We can simulate the problem by using telnet instead of nc command to check the open port. Some other tools abruptly end the connections which cause errors in libpq (library which implements PostgreSQL network protocol).

Such entries are also not going to go away. This happens when the server process tries to read packets (Refer: pq_recvbuf function in src/backend/libpq/pqcomm.c) sent from its client-side and then realizes that client-side is already lost. Which means that the client ended communication without a good handshake.

However, there will be a level of savings. Some tools like nmap used to produce both libpq errors and zero size packet error in PostgreSQL 11 as below:

In PostgreSQL12 this pair of errors will reduce to a single one like: could not receive data from client: Connection reset by peer

Final Word

Many tools used across data centers are undergoing improvements for better compatibility with PostgreSQL. As I mentioned in my previous blog post,  Configure HAProxy with PostgreSQL Using Built-in pgsql-check, recent improvements to HAProxy like this commit improves the disconnection of pgsql-check. So messages like LOG: could not receive data from client: Connection reset by peer may not appear in the logs anymore.

When someone wants to transmit a very large log file with a lot of these benign entries for any purpose, including external support, it may be worth removing these entries from the log file before transmitting/sharing them. For example, a simple sed command as follows could remove all startup packet related log entries:

A less bloated PostgreSQL log file could be an added benefit when you upgrade to PostgreSQL 12, which is one more reason for doing so.

Share this post

Comments (2)

  • zedwareg Reply

    If there are too many “bad” connections like this, does postgresql provide
    some statistics like, the number of “bad” connections those with incomplete
    packet, and those with hard reset?

    December 5, 2019 at 10:03 pm
    • Jobin Augustine Reply

      PostgreSQL won’t store such information inside database. but data will be available in log files. External tooling can parse the log files and store if required. Alternatively log file in CSV format can be used by file_fdw

      December 6, 2019 at 6:30 am

Leave a Reply