Thread: incomplete startup packet messages in logs
Hi Team,
I know this is has been answered a lot on the internet wrt ignoring,
but i am unable to figure out why I get these messages in logs
"incomplete startup packet"
I have a server running postgresql 10.5 on ubuntu16.04
i do not have any active external connections other than streaming
postgres replication.
postgres 7757 1 0 12:20 ? 00:00:00
/usr/lib/postgresql/10/bin/postgres -D /var/lib/postgresql/10/main -c
config_file=/etc/postgresql/10/main/postgresql.conf
postgres 7759 7757 0 12:20 ? 00:00:00 postgres: 10/main:
checkpointer process
postgres 7760 7757 0 12:20 ? 00:00:00 postgres: 10/main:
writer process
postgres 7761 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal
writer process
postgres 7762 7757 0 12:20 ? 00:00:00 postgres: 10/main:
autovacuum launcher process
postgres 7763 7757 0 12:20 ? 00:00:00 postgres: 10/main:
archiver process
postgres 7764 7757 0 12:20 ? 00:00:00 postgres: 10/main:
stats collector process
postgres 7765 7757 0 12:20 ? 00:00:00 postgres: 10/main:
bgworker: logical replication launcher
postgres 7779 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal
sender process replicator x.x.x.x(47792) streaming 3/FA0001B0
postgres 7780 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal
sender process replicator x.x.x.x(50526) streaming 3/FA0001B0
postgres 7786 7757 0 12:21 ? 00:00:00 postgres: 10/main: wal
sender process barman_streaming x.x.x.x(43566) streaming 3/FA0001B0
also,
postgres=# select backend_type, query from pg_stat_activity;
backend_type | query
---------------------+---------------------------------------------------
autovacuum launcher |
background worker |
walsender |
walsender |
walsender |
client backend | select backend_type, query from pg_stat_activity;
background writer |
checkpointer |
walwriter |
but i still see
tail -1000 /var/log/postgresql/postgresql-10-main.log| grep
'incomplete startup packet'
2018-11-01 13:04:18 UTC LOG: incomplete startup packet
2018-11-01 13:08:18 UTC LOG: incomplete startup packet
2018-11-01 13:12:18 UTC LOG: incomplete startup packet
Note: exactly at 4 min interval.
i do not know C, but i tried to understand something from
https://github.com/postgres/postgres/blob/197e4af9d5da180190a0f2be851b095dba57d9cd/src/backend/postmaster/postmaster.c#L1891
without any active connections, i would rule any driver issue out.
i do not have ssl enabled, but not using it. I tried disabling it too.
postgres=# show ssl;
ssl
-----
off
(1 row)
I do not know, why those log messages are then showing up.
not errors in
ens160 Link encap:Ethernet HWaddr 00:50:56:a4:53:b6
inet addr:x.x.x.x Bcast:x.x.x.x Mask:x.x.x.x
inet6 addr: xxxxx/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:45403371 errors:0 dropped:0 overruns:0 frame:0
TX packets:8834699 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:6417380742 (6.4 GB) TX bytes:56209193635 (56.2 GB)
lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
inet6 addr: ::1/128 Scope:Host
UP LOOPBACK RUNNING MTU:65536 Metric:1
RX packets:28985185 errors:0 dropped:0 overruns:0 frame:0
TX packets:28985185 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1
RX bytes:7078785550 (7.0 GB) TX bytes:7078785550 (7.0 GB)
Regards,
Vijay
> On Nov 1, 2018, at 1:27 PM, Vijaykumar Jain <vjain@opentable.com> wrote: > > Hi Team, > > I know this is has been answered a lot on the internet wrt ignoring, > but i am unable to figure out why I get these messages in logs > "incomplete startup packet" Check which of your monitoring systems is configured to check postgresql liveness 15 times an hour. If you can't find it, and you care about the log entries, start sniffing packets to see where the traffic is coming from. > > tail -1000 /var/log/postgresql/postgresql-10-main.log| grep > 'incomplete startup packet' > > 2018-11-01 13:04:18 UTC LOG: incomplete startup packet > > 2018-11-01 13:08:18 UTC LOG: incomplete startup packet > > 2018-11-01 13:12:18 UTC LOG: incomplete startup packet > > > Note: exactly at 4 min interval. Cheers, Steve
ok i enabled log_connections 2018-11-01 13:44:18 UTC LOG: connection received: host=::1 port=47574 2018-11-01 13:44:18 UTC LOG: incomplete startup packet i see this in my /etc/hosts ::1 localhost ip6-localhost ip6-loopback and host all all ::1/128 md5 in my hba,conf i'll check why there is an attempt to make a connection. Regards, Vijay On Thu, Nov 1, 2018 at 6:57 PM Vijaykumar Jain <vjain@opentable.com> wrote: > > Hi Team, > > I know this is has been answered a lot on the internet wrt ignoring, > but i am unable to figure out why I get these messages in logs > "incomplete startup packet" > > I have a server running postgresql 10.5 on ubuntu16.04 > > i do not have any active external connections other than streaming > postgres replication. > > > postgres 7757 1 0 12:20 ? 00:00:00 > /usr/lib/postgresql/10/bin/postgres -D /var/lib/postgresql/10/main -c > config_file=/etc/postgresql/10/main/postgresql.conf > > postgres 7759 7757 0 12:20 ? 00:00:00 postgres: 10/main: > checkpointer process > > postgres 7760 7757 0 12:20 ? 00:00:00 postgres: 10/main: > writer process > > postgres 7761 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal > writer process > > postgres 7762 7757 0 12:20 ? 00:00:00 postgres: 10/main: > autovacuum launcher process > > postgres 7763 7757 0 12:20 ? 00:00:00 postgres: 10/main: > archiver process > > postgres 7764 7757 0 12:20 ? 00:00:00 postgres: 10/main: > stats collector process > > postgres 7765 7757 0 12:20 ? 00:00:00 postgres: 10/main: > bgworker: logical replication launcher > > postgres 7779 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal > sender process replicator x.x.x.x(47792) streaming 3/FA0001B0 > > postgres 7780 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal > sender process replicator x.x.x.x(50526) streaming 3/FA0001B0 > > postgres 7786 7757 0 12:21 ? 00:00:00 postgres: 10/main: wal > sender process barman_streaming x.x.x.x(43566) streaming 3/FA0001B0 > > > > also, > > postgres=# select backend_type, query from pg_stat_activity; > > backend_type | query > > ---------------------+--------------------------------------------------- > > autovacuum launcher | > > background worker | > > walsender | > > walsender | > > walsender | > > client backend | select backend_type, query from pg_stat_activity; > > background writer | > > checkpointer | > > walwriter | > > > > but i still see > > > tail -1000 /var/log/postgresql/postgresql-10-main.log| grep > 'incomplete startup packet' > > 2018-11-01 13:04:18 UTC LOG: incomplete startup packet > > 2018-11-01 13:08:18 UTC LOG: incomplete startup packet > > 2018-11-01 13:12:18 UTC LOG: incomplete startup packet > > > Note: exactly at 4 min interval. > > i do not know C, but i tried to understand something from > https://github.com/postgres/postgres/blob/197e4af9d5da180190a0f2be851b095dba57d9cd/src/backend/postmaster/postmaster.c#L1891 > > without any active connections, i would rule any driver issue out. > > i do not have ssl enabled, but not using it. I tried disabling it too. > > postgres=# show ssl; > > ssl > > ----- > > off > > (1 row) > > > > I do not know, why those log messages are then showing up. > > not errors in > > ens160 Link encap:Ethernet HWaddr 00:50:56:a4:53:b6 > > inet addr:x.x.x.x Bcast:x.x.x.x Mask:x.x.x.x > > inet6 addr: xxxxx/64 Scope:Link > > UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 > > RX packets:45403371 errors:0 dropped:0 overruns:0 frame:0 > > TX packets:8834699 errors:0 dropped:0 overruns:0 carrier:0 > > collisions:0 txqueuelen:1000 > > RX bytes:6417380742 (6.4 GB) TX bytes:56209193635 (56.2 GB) > > > lo Link encap:Local Loopback > > inet addr:127.0.0.1 Mask:255.0.0.0 > > inet6 addr: ::1/128 Scope:Host > > UP LOOPBACK RUNNING MTU:65536 Metric:1 > > RX packets:28985185 errors:0 dropped:0 overruns:0 frame:0 > > TX packets:28985185 errors:0 dropped:0 overruns:0 carrier:0 > > collisions:0 txqueuelen:1 > > RX bytes:7078785550 (7.0 GB) TX bytes:7078785550 (7.0 GB) > > > > > > > > Regards, > Vijay
i have disabled all monitoring i am aware of for postgresql. ( it is sensu/collectd/ and occasional queries via haproxy and pgbouncer) i have disabled them all. i did tcpdump (i am not a pro here), but ignored the ip6 loopback. i'll paste the output once i get again. Regards, Vijay On Thu, Nov 1, 2018 at 7:17 PM Vijaykumar Jain <vjain@opentable.com> wrote: > > ok i enabled log_connections > > 2018-11-01 13:44:18 UTC LOG: connection received: host=::1 port=47574 > 2018-11-01 13:44:18 UTC LOG: incomplete startup packet > > i see this in my /etc/hosts > > ::1 localhost ip6-localhost ip6-loopback > > > and > > host all all ::1/128 md5 > > in my hba,conf > > > i'll check why there is an attempt to make a connection. > > > Regards, > Vijay > On Thu, Nov 1, 2018 at 6:57 PM Vijaykumar Jain <vjain@opentable.com> wrote: > > > > Hi Team, > > > > I know this is has been answered a lot on the internet wrt ignoring, > > but i am unable to figure out why I get these messages in logs > > "incomplete startup packet" > > > > I have a server running postgresql 10.5 on ubuntu16.04 > > > > i do not have any active external connections other than streaming > > postgres replication. > > > > > > postgres 7757 1 0 12:20 ? 00:00:00 > > /usr/lib/postgresql/10/bin/postgres -D /var/lib/postgresql/10/main -c > > config_file=/etc/postgresql/10/main/postgresql.conf > > > > postgres 7759 7757 0 12:20 ? 00:00:00 postgres: 10/main: > > checkpointer process > > > > postgres 7760 7757 0 12:20 ? 00:00:00 postgres: 10/main: > > writer process > > > > postgres 7761 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal > > writer process > > > > postgres 7762 7757 0 12:20 ? 00:00:00 postgres: 10/main: > > autovacuum launcher process > > > > postgres 7763 7757 0 12:20 ? 00:00:00 postgres: 10/main: > > archiver process > > > > postgres 7764 7757 0 12:20 ? 00:00:00 postgres: 10/main: > > stats collector process > > > > postgres 7765 7757 0 12:20 ? 00:00:00 postgres: 10/main: > > bgworker: logical replication launcher > > > > postgres 7779 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal > > sender process replicator x.x.x.x(47792) streaming 3/FA0001B0 > > > > postgres 7780 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal > > sender process replicator x.x.x.x(50526) streaming 3/FA0001B0 > > > > postgres 7786 7757 0 12:21 ? 00:00:00 postgres: 10/main: wal > > sender process barman_streaming x.x.x.x(43566) streaming 3/FA0001B0 > > > > > > > > also, > > > > postgres=# select backend_type, query from pg_stat_activity; > > > > backend_type | query > > > > ---------------------+--------------------------------------------------- > > > > autovacuum launcher | > > > > background worker | > > > > walsender | > > > > walsender | > > > > walsender | > > > > client backend | select backend_type, query from pg_stat_activity; > > > > background writer | > > > > checkpointer | > > > > walwriter | > > > > > > > > but i still see > > > > > > tail -1000 /var/log/postgresql/postgresql-10-main.log| grep > > 'incomplete startup packet' > > > > 2018-11-01 13:04:18 UTC LOG: incomplete startup packet > > > > 2018-11-01 13:08:18 UTC LOG: incomplete startup packet > > > > 2018-11-01 13:12:18 UTC LOG: incomplete startup packet > > > > > > Note: exactly at 4 min interval. > > > > i do not know C, but i tried to understand something from > > https://github.com/postgres/postgres/blob/197e4af9d5da180190a0f2be851b095dba57d9cd/src/backend/postmaster/postmaster.c#L1891 > > > > without any active connections, i would rule any driver issue out. > > > > i do not have ssl enabled, but not using it. I tried disabling it too. > > > > postgres=# show ssl; > > > > ssl > > > > ----- > > > > off > > > > (1 row) > > > > > > > > I do not know, why those log messages are then showing up. > > > > not errors in > > > > ens160 Link encap:Ethernet HWaddr 00:50:56:a4:53:b6 > > > > inet addr:x.x.x.x Bcast:x.x.x.x Mask:x.x.x.x > > > > inet6 addr: xxxxx/64 Scope:Link > > > > UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 > > > > RX packets:45403371 errors:0 dropped:0 overruns:0 frame:0 > > > > TX packets:8834699 errors:0 dropped:0 overruns:0 carrier:0 > > > > collisions:0 txqueuelen:1000 > > > > RX bytes:6417380742 (6.4 GB) TX bytes:56209193635 (56.2 GB) > > > > > > lo Link encap:Local Loopback > > > > inet addr:127.0.0.1 Mask:255.0.0.0 > > > > inet6 addr: ::1/128 Scope:Host > > > > UP LOOPBACK RUNNING MTU:65536 Metric:1 > > > > RX packets:28985185 errors:0 dropped:0 overruns:0 frame:0 > > > > TX packets:28985185 errors:0 dropped:0 overruns:0 carrier:0 > > > > collisions:0 txqueuelen:1 > > > > RX bytes:7078785550 (7.0 GB) TX bytes:7078785550 (7.0 GB) > > > > > > > > > > > > > > > > Regards, > > Vijay
Thanks Steve,
It was indeed monitoring.
i just had one check enabled, except the others which was not a check
that queried postgres but a simple tcp port available.
check-ports.rb -H localhost -p 5432
which was basically just creating a socket to check if it is is
listening but not closing it.
$:~# irb
irb(main):001:0> require 'socket';
irb(main):002:0* a = TCPSocket.new('localhost', 5432)
=> #<TCPSocket:fd 7>
irb(main):003:0> ^C
and in logs
2018-11-01 14:05:10 UTC LOG: connection received: host=127.0.0.1 port=59786
2018-11-01 14:05:24 UTC LOG: incomplete startup packet
so indeed it is monitoring as it is on the internet :)
but thanks for helping out :)
Regards,
Vijay
On Thu, Nov 1, 2018 at 7:20 PM Vijaykumar Jain <vjain@opentable.com> wrote:
>
> i have disabled all monitoring i am aware of for postgresql. ( it is
> sensu/collectd/ and occasional queries via haproxy and pgbouncer) i
> have disabled them all.
>
> i did tcpdump (i am not a pro here), but ignored the ip6 loopback.
> i'll paste the output once i get again.
>
>
>
> Regards,
> Vijay
>
> On Thu, Nov 1, 2018 at 7:17 PM Vijaykumar Jain <vjain@opentable.com> wrote:
> >
> > ok i enabled log_connections
> >
> > 2018-11-01 13:44:18 UTC LOG: connection received: host=::1 port=47574
> > 2018-11-01 13:44:18 UTC LOG: incomplete startup packet
> >
> > i see this in my /etc/hosts
> >
> > ::1 localhost ip6-localhost ip6-loopback
> >
> >
> > and
> >
> > host all all ::1/128 md5
> >
> > in my hba,conf
> >
> >
> > i'll check why there is an attempt to make a connection.
> >
> >
> > Regards,
> > Vijay
> > On Thu, Nov 1, 2018 at 6:57 PM Vijaykumar Jain <vjain@opentable.com> wrote:
> > >
> > > Hi Team,
> > >
> > > I know this is has been answered a lot on the internet wrt ignoring,
> > > but i am unable to figure out why I get these messages in logs
> > > "incomplete startup packet"
> > >
> > > I have a server running postgresql 10.5 on ubuntu16.04
> > >
> > > i do not have any active external connections other than streaming
> > > postgres replication.
> > >
> > >
> > > postgres 7757 1 0 12:20 ? 00:00:00
> > > /usr/lib/postgresql/10/bin/postgres -D /var/lib/postgresql/10/main -c
> > > config_file=/etc/postgresql/10/main/postgresql.conf
> > >
> > > postgres 7759 7757 0 12:20 ? 00:00:00 postgres: 10/main:
> > > checkpointer process
> > >
> > > postgres 7760 7757 0 12:20 ? 00:00:00 postgres: 10/main:
> > > writer process
> > >
> > > postgres 7761 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal
> > > writer process
> > >
> > > postgres 7762 7757 0 12:20 ? 00:00:00 postgres: 10/main:
> > > autovacuum launcher process
> > >
> > > postgres 7763 7757 0 12:20 ? 00:00:00 postgres: 10/main:
> > > archiver process
> > >
> > > postgres 7764 7757 0 12:20 ? 00:00:00 postgres: 10/main:
> > > stats collector process
> > >
> > > postgres 7765 7757 0 12:20 ? 00:00:00 postgres: 10/main:
> > > bgworker: logical replication launcher
> > >
> > > postgres 7779 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal
> > > sender process replicator x.x.x.x(47792) streaming 3/FA0001B0
> > >
> > > postgres 7780 7757 0 12:20 ? 00:00:00 postgres: 10/main: wal
> > > sender process replicator x.x.x.x(50526) streaming 3/FA0001B0
> > >
> > > postgres 7786 7757 0 12:21 ? 00:00:00 postgres: 10/main: wal
> > > sender process barman_streaming x.x.x.x(43566) streaming 3/FA0001B0
> > >
> > >
> > >
> > > also,
> > >
> > > postgres=# select backend_type, query from pg_stat_activity;
> > >
> > > backend_type | query
> > >
> > > ---------------------+---------------------------------------------------
> > >
> > > autovacuum launcher |
> > >
> > > background worker |
> > >
> > > walsender |
> > >
> > > walsender |
> > >
> > > walsender |
> > >
> > > client backend | select backend_type, query from pg_stat_activity;
> > >
> > > background writer |
> > >
> > > checkpointer |
> > >
> > > walwriter |
> > >
> > >
> > >
> > > but i still see
> > >
> > >
> > > tail -1000 /var/log/postgresql/postgresql-10-main.log| grep
> > > 'incomplete startup packet'
> > >
> > > 2018-11-01 13:04:18 UTC LOG: incomplete startup packet
> > >
> > > 2018-11-01 13:08:18 UTC LOG: incomplete startup packet
> > >
> > > 2018-11-01 13:12:18 UTC LOG: incomplete startup packet
> > >
> > >
> > > Note: exactly at 4 min interval.
> > >
> > > i do not know C, but i tried to understand something from
> > >
https://github.com/postgres/postgres/blob/197e4af9d5da180190a0f2be851b095dba57d9cd/src/backend/postmaster/postmaster.c#L1891
> > >
> > > without any active connections, i would rule any driver issue out.
> > >
> > > i do not have ssl enabled, but not using it. I tried disabling it too.
> > >
> > > postgres=# show ssl;
> > >
> > > ssl
> > >
> > > -----
> > >
> > > off
> > >
> > > (1 row)
> > >
> > >
> > >
> > > I do not know, why those log messages are then showing up.
> > >
> > > not errors in
> > >
> > > ens160 Link encap:Ethernet HWaddr 00:50:56:a4:53:b6
> > >
> > > inet addr:x.x.x.x Bcast:x.x.x.x Mask:x.x.x.x
> > >
> > > inet6 addr: xxxxx/64 Scope:Link
> > >
> > > UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
> > >
> > > RX packets:45403371 errors:0 dropped:0 overruns:0 frame:0
> > >
> > > TX packets:8834699 errors:0 dropped:0 overruns:0 carrier:0
> > >
> > > collisions:0 txqueuelen:1000
> > >
> > > RX bytes:6417380742 (6.4 GB) TX bytes:56209193635 (56.2 GB)
> > >
> > >
> > > lo Link encap:Local Loopback
> > >
> > > inet addr:127.0.0.1 Mask:255.0.0.0
> > >
> > > inet6 addr: ::1/128 Scope:Host
> > >
> > > UP LOOPBACK RUNNING MTU:65536 Metric:1
> > >
> > > RX packets:28985185 errors:0 dropped:0 overruns:0 frame:0
> > >
> > > TX packets:28985185 errors:0 dropped:0 overruns:0 carrier:0
> > >
> > > collisions:0 txqueuelen:1
> > >
> > > RX bytes:7078785550 (7.0 GB) TX bytes:7078785550 (7.0 GB)
> > >
> > >
> > >
> > >
> > >
> > >
> > >
> > > Regards,
> > > Vijay