Incomplete startup packet errors

At 2016-04-13 10:02:22 +0200, magnus@hagander.net wrote:

I wonder if it would make sense to only log that error if *at least
one byte* has been received and then it becomes empty.

Yes, it would be very nice to eliminate that logspam, as you say.

-- Abhijit

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Wed, Apr 13, 2016 at 9:02 AM, Magnus Hagander <magnus@hagander.net> wrote:

It's fairly common to see a lot of "Incomplete startup packet" in the
logfiles caused by monitoring or healthcheck connections.

I wonder if it would make sense to only log that error if *at least one
byte* has been received and then it becomes empty. Meaning that if the
client just connects+disconnects without sending anything, we don't log
anything. At least at the default log level (we could have a DEBUG level
that logged "connection closed immediately").

That would get rid of a lot of logspam.

Would that make sense?

Absolutely. It would be very nice to get rid of such noise.

--
Dave Page
Blog: http://pgsnake.blogspot.com
Twitter: @pgsnake

EnterpriseDB UK: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Wed, Apr 13, 2016 at 1:02 AM, Magnus Hagander <magnus@hagander.net> wrote:

It's fairly common to see a lot of "Incomplete startup packet" in the
logfiles caused by monitoring or healthcheck connections.

I've also seen it caused by port scanning.

--
Peter Geoghegan

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Wed, Apr 13, 2016 at 10:24 AM, Peter Geoghegan <pg@heroku.com> wrote:

On Wed, Apr 13, 2016 at 1:02 AM, Magnus Hagander <magnus@hagander.net>
wrote:

It's fairly common to see a lot of "Incomplete startup packet" in the
logfiles caused by monitoring or healthcheck connections.

I've also seen it caused by port scanning.

Yes, definitely. Question there might be if that's actually a case when we
*want* that logging?

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

Magnus Hagander <magnus@hagander.net> writes:

On Wed, Apr 13, 2016 at 10:24 AM, Peter Geoghegan <pg@heroku.com> wrote:

On Wed, Apr 13, 2016 at 1:02 AM, Magnus Hagander <magnus@hagander.net>
wrote:

It's fairly common to see a lot of "Incomplete startup packet" in the
logfiles caused by monitoring or healthcheck connections.

I've also seen it caused by port scanning.

Yes, definitely. Question there might be if that's actually a case when we
*want* that logging?

I should think someone might. But I doubt we want to introduce another
GUC for this. Would it be okay to downgrade the message to DEBUG1 if
zero bytes were received?

regards, tom lane

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Wed, Apr 13, 2016 at 3:56 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Magnus Hagander <magnus@hagander.net> writes:

On Wed, Apr 13, 2016 at 10:24 AM, Peter Geoghegan <pg@heroku.com> wrote:

On Wed, Apr 13, 2016 at 1:02 AM, Magnus Hagander <magnus@hagander.net>
wrote:

It's fairly common to see a lot of "Incomplete startup packet" in the
logfiles caused by monitoring or healthcheck connections.

I've also seen it caused by port scanning.

Yes, definitely. Question there might be if that's actually a case when

we

*want* that logging?

I should think someone might. But I doubt we want to introduce another
GUC for this. Would it be okay to downgrade the message to DEBUG1 if
zero bytes were received?

Yeah, that was my suggestion - I think that's a reasonable compromise. And
yes, I agree that a separate GUC for it would be a huge overkill.

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

I've also seen it caused by port scanning.

Yes, definitely. Question there might be if that's actually a case when we
*want* that logging?

Is it possible a user want the log because he/she wants to notice that
the system is being attacked?
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Wed, Apr 13, 2016 at 10:30 AM, Tatsuo Ishii <ishii@postgresql.org> wrote:

I've also seen it caused by port scanning.

Yes, definitely. Question there might be if that's actually a case when we
*want* that logging?

Is it possible a user want the log because he/she wants to notice that
the system is being attacked?

Yeah, but it doesn't seem very likely, because:

1. If the system is on the Internet, it's definitely being attacked, and

2. The attacks that connect to a port and then disconnect are not the
ones you should be most worried about, and

3. The right way to detect attacks is through OS-level monitoring or
firewall-level monitoring, and nothing we do in PG is going to come
close to the same value.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Is it possible a user want the log because he/she wants to notice that
the system is being attacked?

Yeah, but it doesn't seem very likely, because:

1. If the system is on the Internet, it's definitely being attacked, and

2. The attacks that connect to a port and then disconnect are not the
ones you should be most worried about, and

3. The right way to detect attacks is through OS-level monitoring or
firewall-level monitoring, and nothing we do in PG is going to come
close to the same value.

Ok, that makes sense.

Best regards,
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: Magnus Hagander 2016-04-13 <CABUevEzq8_nSq7fwe0-fbOAK8S2YNN-PkfsamfEvy2-d3dRUoA@mail.gmail.com>

It's fairly common to see a lot of "Incomplete startup packet" in the
logfiles caused by monitoring or healthcheck connections.

I've also seen it caused by port scanning.

Yes, definitely. Question there might be if that's actually a case when

we

*want* that logging?

I should think someone might. But I doubt we want to introduce another
GUC for this. Would it be okay to downgrade the message to DEBUG1 if
zero bytes were received?

Yeah, that was my suggestion - I think that's a reasonable compromise. And
yes, I agree that a separate GUC for it would be a huge overkill.

There have been numerous complaints about that log message, and the
usual reply is always something like what Pavel said recently:

"It is garbage. Usually it means nothing, but better to work live
without this garbage." [1]/messages/by-id/CAFj8pRDtwsxj63=LaWSwA8u7NrU9k9+dJtz2gB_0f4SxCM1sQA@mail.gmail.com

[1]: /messages/by-id/CAFj8pRDtwsxj63=LaWSwA8u7NrU9k9+dJtz2gB_0f4SxCM1sQA@mail.gmail.com

Let's get rid of it.

Christoph

On 2/28/19 10:13 AM, Christoph Berg wrote:

Re: Magnus Hagander 2016-04-13 <CABUevEzq8_nSq7fwe0-fbOAK8S2YNN-PkfsamfEvy2-d3dRUoA@mail.gmail.com>

It's fairly common to see a lot of "Incomplete startup packet" in the
logfiles caused by monitoring or healthcheck connections.

I've also seen it caused by port scanning.

Yes, definitely. Question there might be if that's actually a case when

we

*want* that logging?

I should think someone might. But I doubt we want to introduce another
GUC for this. Would it be okay to downgrade the message to DEBUG1 if
zero bytes were received?

Yeah, that was my suggestion - I think that's a reasonable compromise. And
yes, I agree that a separate GUC for it would be a huge overkill.

There have been numerous complaints about that log message, and the
usual reply is always something like what Pavel said recently:

"It is garbage. Usually it means nothing, but better to work live
without this garbage." [1]

[1] /messages/by-id/CAFj8pRDtwsxj63=LaWSwA8u7NrU9k9+dJtz2gB_0f4SxCM1sQA@mail.gmail.com

Let's get rid of it.

Right. This has annoyed me and a great many other people for years. I
think Robert Haas' argument 3 years ago (!) was on point, and disposes
of suggestions to keep it:

3. The right way to detect attacks is through OS-level monitoring or
firewall-level monitoring, and nothing we do in PG is going to come
close to the same value.

So I propose shortly to commit this patch unconditionally demoting the
message to DEBUG1.

cheers

andrew

--
Andrew Dunstan https://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Andrew Dunstan <andrew.dunstan@2ndquadrant.com> writes:

So I propose shortly to commit this patch unconditionally demoting the
message to DEBUG1.

No patch referenced, but I assume you mean only for the
zero-bytes-received case, right? No objection if so.

regards, tom lane

On 3/1/19 6:49 PM, Tom Lane wrote:

Andrew Dunstan <andrew.dunstan@2ndquadrant.com> writes:

So I propose shortly to commit this patch unconditionally demoting the
message to DEBUG1.

No patch referenced, but I assume you mean only for the
zero-bytes-received case, right? No objection if so.

Patch proposed by Christoph Berg is here:

/messages/by-id/20190228151336.GB7550@msg.df7cb.de

cheers

andrew

--
Andrew Dunstan https://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Andrew Dunstan <andrew.dunstan@2ndquadrant.com> writes:

On 3/1/19 6:49 PM, Tom Lane wrote:

No patch referenced, but I assume you mean only for the
zero-bytes-received case, right? No objection if so.

Patch proposed by Christoph Berg is here:
/messages/by-id/20190228151336.GB7550@msg.df7cb.de

Meh. That doesn't silence only the zero-bytes case, and I'm also
rather afraid of the fact that it's changing COMMERROR to something
else. I wonder whether (if client_min_messages <= DEBUG1) it could
result in trying to send the error message to the already-lost
connection. It might be that that can't happen, but I think a fair
amount of rather subtle (and breakable) analysis may be needed.

regards, tom lane

I wrote:

Andrew Dunstan <andrew.dunstan@2ndquadrant.com> writes:

Patch proposed by Christoph Berg is here:
/messages/by-id/20190228151336.GB7550@msg.df7cb.de

Meh. That doesn't silence only the zero-bytes case, and I'm also
rather afraid of the fact that it's changing COMMERROR to something
else. I wonder whether (if client_min_messages <= DEBUG1) it could
result in trying to send the error message to the already-lost
connection. It might be that that can't happen, but I think a fair
amount of rather subtle (and breakable) analysis may be needed.

Concretely, what about doing the following instead? This doesn't provide
any mechanism for the DBA to adjust the logging behavior; but reducing
log_min_messages to DEBUG1 would not be a very pleasant way to monitor for
zero-data connections either, so I'm not that fussed about just dropping
the message period for that case. I kind of like that we no longer need
the weird special case for SSLdone.

regards, tom lane

On 3/3/19 3:52 PM, Tom Lane wrote:

I wrote:

Andrew Dunstan <andrew.dunstan@2ndquadrant.com> writes:

Patch proposed by Christoph Berg is here:
/messages/by-id/20190228151336.GB7550@msg.df7cb.de

Meh. That doesn't silence only the zero-bytes case, and I'm also
rather afraid of the fact that it's changing COMMERROR to something
else. I wonder whether (if client_min_messages <= DEBUG1) it could
result in trying to send the error message to the already-lost
connection. It might be that that can't happen, but I think a fair
amount of rather subtle (and breakable) analysis may be needed.

Concretely, what about doing the following instead? This doesn't provide
any mechanism for the DBA to adjust the logging behavior; but reducing
log_min_messages to DEBUG1 would not be a very pleasant way to monitor for
zero-data connections either, so I'm not that fussed about just dropping
the message period for that case. I kind of like that we no longer need
the weird special case for SSLdone.

Looks good to me.

cheers

andrew

--
Andrew Dunstan https://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: Andrew Dunstan 2019-03-04 <7cc6d2c1-bd87-9890-259d-36739c247b6c@2ndQuadrant.com>

Looks good to me.

+1.

Christoph

On 3/4/19 7:42 AM, Christoph Berg wrote:

Re: Andrew Dunstan 2019-03-04 <7cc6d2c1-bd87-9890-259d-36739c247b6c@2ndQuadrant.com>

Looks good to me.

+1.

OK, I think we have agreement on Tom's patch. Do we want to backpatch
it? It's a change in behaviour, but I find it hard to believe anyone
relies on the existence of these annoying messages, so my vote would be
to backpatch it.

cheers

andrew

--
Andrew Dunstan https://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On Tue, Mar 5, 2019 at 5:35 PM Andrew Dunstan
<andrew.dunstan@2ndquadrant.com> wrote:

OK, I think we have agreement on Tom's patch. Do we want to backpatch
it? It's a change in behaviour, but I find it hard to believe anyone
relies on the existence of these annoying messages, so my vote would be
to backpatch it.

I don't think it's a bug fix, so I don't think it should be
back-patched. I think trying to guess which behavior changes are
likely to bother users is an unwise strategy -- it's very hard to know
what will actually bother people, and it's very easy to let one's own
desire to get a fix out the door lead to an unduly rosy view of the
situation. Plus, all patches carry some risk, because all developers
make mistakes; the fewer things we back-patch, the fewer regressions
we'll introduce.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company