lighty labs

2021-09-16

09:26 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

Thanks for your tip about my FastCGI backend. You where correct about a random byte was checked when the connection w... stenvaag

09:00 Lighttpd Bug #3102 (Fixed): Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

Applied in changeset commit:94bac825dc03fe30f9d2b6067d589a31902502fb. gstrauss

08:57 Lighttpd Bug #3102 (Patch Pending): Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

Great! Thank you very much for your time and persistence in helping track this down.
This tightens up the code a ... gstrauss

08:30 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

I'm now unable to get the error.
...
1631780629.700954970: (h2.c.1891) fd:10 id:2639 resp: server: lighttpd/1.4.6... stenvaag

08:05 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

It looks like there is a short period of time after lighttpd decides to close the idle connection, and during which n... gstrauss

07:32 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

... stenvaag

04:19 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

Some additional patches which might help your tracing. There are all optional and for testing only. The patch to @l... gstrauss

08:40 Lighttpd Revision 6ffabc96: [core] default backend "connect-timeout" to 8 (#3086)

default backend "connect-timeout" to 8 seconds
Though this is is a behavior change where there previously was no
tim... gstrauss

08:40 Lighttpd Revision 94bac825: [core] HTTP/2 GOAWAY after timeout before read (fixes #3102)

HTTP/2 send GOAWAY soon after keep-alive timeout, before potentially
reading new stream requests, which will then hav... gstrauss

08:40 Lighttpd Revision 0b56c16a: [core] reduce oversized mem alloc for backends

reduce oversized memory allocations when reading from backends:
avoid extra power-2 allocation for 1 byte ('\0') when... gstrauss

08:22 Lighttpd Bug #3103 (Duplicate): Constant growing memory usage

Thanks.
> But I vote for enabling at least a connect timeout by default, in haproxy I typically set it to 5 second... gstrauss

07:49 Lighttpd Bug #3103: Constant growing memory usage

Sorry, I have not expressed myself clearly enough:
* the timeouts are working and DO solve the problem
* I disabled... flynn

03:24 Lighttpd Bug #3103: Constant growing memory usage

Potential improvement: I could set the default for "connect-timeout" to be something like 5 or 10 or 15 seconds.
Whi... gstrauss

03:40 Lighttpd Revision 94053349: [core] remove redundant check in h2_recv_headers()

(comment out redundant check in h2_recv_headers()) gstrauss

2021-09-15

22:27 Lighttpd Bug #3103: Constant growing memory usage

> I tested the new timeouts and disabled them again to be able to switch back.
I am glad you were able to track th... gstrauss

21:36 Lighttpd Bug #3103: Constant growing memory usage

I found the issue, it's related to ticket #3086.
I tested the new timeouts and disabled them again to be able to swi... flynn

09:57 Lighttpd Bug #3103: Constant growing memory usage

@valgrind --tool=memcheck --leak-check=full --track-origins=yes --show-leak-kinds=all --track-fds=yes --log-file=/var... gstrauss

08:29 Lighttpd Bug #3103: Constant growing memory usage

> It must be a change, that came through git-rebasing ... any idea?
Hmmm. I have a copy of my dev repo on a volum... gstrauss

07:56 Lighttpd Bug #3103: Constant growing memory usage

I have two servers in test:
* the low volume server still has very good memory usage with current git version
* on ... flynn

07:52 Lighttpd Bug #3103: Constant growing memory usage

I recognized your changes regarding the multiple log files, it works for me, the file handles are reduced.
I do NO... flynn

07:00 Lighttpd Bug #3103: Constant growing memory usage

That memory use appears to be a step function. By chance, are you rotating logs every half-hour? (Do you send SIGHU... gstrauss

06:02 Lighttpd Bug #3103: Constant growing memory usage

ick. that's not good.
My guess is that there must be some leak in the patches for #3101, since that is the big ch... gstrauss

05:29 Lighttpd Bug #3103 (Duplicate): Constant growing memory usage

After fixing ticket #3084 the memory usage was perfect for some days.
On Monday morning I updated my git tree and ... flynn

18:45 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

At first glance, that appears to be proper behavior.
@2021-09-15 13:55:34: connections.c.1458) connection closed - ke... gstrauss

12:00 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

I modified connections.c to only include "connection closed" messages. Then I was able to get the protocol error:
<pr... stenvaag

11:42 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

> Is there anything in the lighttpd error log around that time?
You have a complete copy of the error.log.
Look... stenvaag

11:30 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

The connection with the GET for "driftsenheter" in the log, the last one at "12:49:19" looks like it (the connection)... gstrauss

11:10 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

I'm unable to get the error with debug.log-state-handling = "enable" stenvaag

11:01 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

Attached is a log with server.max-read-idle = 1. A grep for "driftsenheter" in the log, the last one at "12:49:19" fa... stenvaag

10:56 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

I have no knowledge about trailers. stenvaag

10:45 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

Looking at error_log.zip and trying to match up against what you posted above, it looks like you may have selected @f... gstrauss

10:15 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

Here is the complete error.log from yestday. stenvaag

10:10 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

With the above patches for trailers I imediately got the protocol error from the first PUT of the 12, the rest succee... stenvaag

09:34 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

id:9 for the PUT request is the 5th client stream on the HTTP/2 connection (1,3,5,7,9), so you might check the logs a... gstrauss

08:07 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

lighttpd @src/h2.c@ currently ignores HTTP trailers. Here's a patch to detect and reject if an HTTP/2 HEADERS frame ... gstrauss

08:02 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

There is probably a "goaway" here that is not logged. I removed all my logging (of goaway). I could try to reinsert, ... stenvaag

07:23 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

That raises (at least) two questions:
* Is Chrome erroneously repeating the same id?
* Why is lighttpd not rejectin... gstrauss

06:59 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

I managed to get the error with request and response logging enabled. I'm still unsure if this is my fcgi backend or ... stenvaag

10:19 Lighttpd2 Revision 29e57d30: [core] re-enable listening sockets

make sure to check once a second whether we can re-enable the listening
sockets.
Change-Id: Ib9844c183de2b8a8bd00baf... stbuehler

09:11 Lighttpd Revision a407636e: [core] reject HTTP/2 pseudo-header in trailers (#3102)

(detect if client erroneously reuses stream id for a different request)
x-ref:
"Chrome gives random net::ERR_HTTP2... gstrauss

2021-09-14

21:45 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

You might test with a burst of requests at connect time (after waiting for lighttpd to close the HTTP/2 connection af... gstrauss

13:01 Lighttpd Bug #3102: Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

> I need some more advice on how to track this down.
Well, I need some sleep :), so here are some ideas to start.
... gstrauss

12:08 Lighttpd Bug #3102 (Fixed): Chrome gives random net::ERR_HTTP2_PROTOCOL_ERROR

When trying with https://git.lighttpd.net/lighttpd/lighttpd1.4/src/branch/master I get random error from Chrome.
n... stenvaag

10:01 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

Yes, I will open a new bug. (I was out of office, but will now look into this.)
I tried to get the error with 1.4.... stenvaag

09:18 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

> this error only appeared in 1.4.59 when the http/2 protocol was activated.
Perhaps we should treat this as a sep... gstrauss

09:14 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

> The error from Chrome is "net::ERR_HTTP2_PROTOCOL_ERROR".
BTW, it still concerns me that you're seeing that. If... gstrauss

08:47 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

FYI: I see 0 failures with @h2load@ running 20000+ request per second against a FastCGI backend written in C (lighttp... gstrauss

08:41 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

lighttpd mod_fastcgi always assigns @header->version = FCGI_VERSION_1;@ when creating FCGI headers.
https://git.ligh... gstrauss

08:29 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

When this occur my fcgi backend reports that first byte received is not 1 (FCGI_VERSION_1), but a random number. This... stenvaag

08:27 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

Would you test with lighttpd 1.4.59 to check if you saw this behavior with lighttpd 1.4.59, too? I have tested with ... gstrauss

08:18 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

It is not easy to get the error. I have to run my application multiple times (reload the page) to possible get the er... stenvaag

07:54 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

> I downloaded and tested https://git.lighttpd.net/lighttpd/lighttpd1.4/src/branch/master 40 minutes ago. "My" error ... gstrauss

07:46 Lighttpd Bug #3093: Chrome 92, HTTP/2, fcgi, mutiple puts no response

I downloaded and tested https://git.lighttpd.net/lighttpd/lighttpd1.4/src/branch/master 40 minutes ago. "My" error is... stenvaag

07:25 Lighttpd Revision af96e52b: [core] quiet coverity warnings

gstrauss

06:45 Lighttpd Bug #3100 (Fixed): Random TLS errors on established connections

Applied in changeset commit:3a5704380b1291bd50fb599ab7eef5a70ff26eb2. gstrauss

06:39 Lighttpd Bug #3100 (Patch Pending): Random TLS errors on established connections

Slightly different patch committed and pushed. gstrauss

06:45 Lighttpd Feature #3101 (Fixed): RFE: de-dup file and piped loggers

Applied in changeset commit:7b615d5d24048d38bd7e8368dd1de91b0d26cbaa. gstrauss

04:05 Lighttpd Revision 3a570438: [core] refuse excess initial streams only if block (fixes #3100)

refuse excess streams only if would block DATA frames for active streams
(for excess streams received on initial conn... gstrauss