Re: [HACKERS] Incomplete startup packet errors

On 2/28/19 10:13 AM, Christoph Berg wrote:
> Re: Magnus Hagander 2016-04-13 <CABUevEzq8_nSq7fwe0-fbOAK8S2YNN-PkfsamfEvy2-d3dRUoA(at)mail(dot)gmail(dot)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] /message-id/CAFj8pRDtwsxj63%3DLaWSwA8u7NrU9k9%2BdJtz2gB_0f4SxCM1sQA%40mail.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(dot)dunstan(at)2ndquadrant(dot)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(dot)dunstan(at)2ndquadrant(dot)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:

/message-id/20190228151336.GB7550%40msg.df7cb.de

cheers

andrew

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

Andrew Dunstan <andrew(dot)dunstan(at)2ndquadrant(dot)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:
> /message-id/20190228151336.GB7550%40msg.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(dot)dunstan(at)2ndquadrant(dot)com> writes:
>> Patch proposed by Christoph Berg is here:
>> /message-id/20190228151336.GB7550%40msg.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(dot)dunstan(at)2ndquadrant(dot)com> writes:
>>> Patch proposed by Christoph Berg is here:
>>> /message-id/20190228151336.GB7550%40msg.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(at)2ndQuadrant(dot)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(at)2ndQuadrant(dot)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(dot)dunstan(at)2ndquadrant(dot)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

On 3/6/19 12:12 PM, Robert Haas wrote:
> On Tue, Mar 5, 2019 at 5:35 PM Andrew Dunstan
> <andrew(dot)dunstan(at)2ndquadrant(dot)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.
>

OK, no back-patching it is.

cheers

andrew

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

On Thu, Mar 7, 2019 at 1:26 AM Andrew Dunstan <
andrew(dot)dunstan(at)2ndquadrant(dot)com> wrote:

>
> On 3/6/19 12:12 PM, Robert Haas wrote:
> > On Tue, Mar 5, 2019 at 5:35 PM Andrew Dunstan
> > <andrew(dot)dunstan(at)2ndquadrant(dot)com> wrote:
> >> OK, I think we have agreement on Tom's patch. Do we want to backpatch
> OK, no back-patching it is.
>
However, Checking whether the port is open is resulting in error log like:
2019-11-25 14:03:44.414 IST [14475] LOG: invalid length of startup packet
Yes, This is different from "Incomplete startup packet" discussed here.

Steps to reproduce:
$ telnet localhost 5432

>
>

Jobin Augustine <jobinau(at)gmail(dot)com> writes:
> However, Checking whether the port is open is resulting in error log like:
> 2019-11-25 14:03:44.414 IST [14475] LOG: invalid length of startup packet
> Yes, This is different from "Incomplete startup packet" discussed here.

> Steps to reproduce:
> $ telnet localhost 5432
>>
>>

Well, the agreed-to behavior change was to not log anything if the
connection is closed without any data having been sent. If the
client *does* send something, and it doesn't look like a valid
connection request, I think we absolutely should log that.

regards, tom lane

Greetings,

* Tom Lane (tgl(at)sss(dot)pgh(dot)pa(dot)us) wrote:
> Jobin Augustine <jobinau(at)gmail(dot)com> writes:
> > However, Checking whether the port is open is resulting in error log like:
> > 2019-11-25 14:03:44.414 IST [14475] LOG: invalid length of startup packet
> > Yes, This is different from "Incomplete startup packet" discussed here.
>
> > Steps to reproduce:
> > $ telnet localhost 5432
>
> Well, the agreed-to behavior change was to not log anything if the
> connection is closed without any data having been sent. If the
> client *does* send something, and it doesn't look like a valid
> connection request, I think we absolutely should log that.

Agreed.

Thanks,

Stephen