Hello!
On Mon, Jan 10, 2022 at 10:10:37AM +0000, Max Dymond wrote:
> I'm trying to use NGINX as an SSL "man in the middle" to (a)
> terminate an SSL stream, (b) parse a binary protocol inside that
> stream to accept or reject messages, (c) connect over SSL to
> another target and send all the accepted messages.
>
> After a bit of investigation I'm trying my hand at a stream
> filter module, and I'm trying to do a very simple module which:
> - splits incoming messages into individual buffers (the protocol
> has well-defined packet sizes)
> - creates chain links for each of these messages.
>
> // Create a new buffer and chain link.
> link = ngx_alloc_chain_link(c->pool);
> if (link == NULL) {
> return NGX_ERROR;
> }
>
> b = ngx_create_temp_buf(c->pool, frame_length);
> link->buf = b;
>
> // Copy the frame into the buffer.
> ngx_memcpy(link->buf->start, pos, frame_length);
> link->buf->last += frame_length;
> link->buf->tag = cl->buf->tag;
> link->buf->flush = cl->buf->flush;
>
>
> This process seems to work but I'm getting an error message when
> I pass my chain to the next filter:
>
> return ngx_stream_next_filter(s, out, from_upstream);
>
> gives
>
> the stream output chain is empty while proxying and sending to upstream, client: 172.20.0.5, server: 0.0.0.0:9043, upstream: "172.20.0.2:9042", bytes from/to client:9/61, bytes from/to upstream:61/9
>
> I've got diagnostics which verify the (single) chainlink I'm
> passing to the next filter:
>
> 2022/01/10 09:26:14 [info] 24#24: *3 MD: OUT chainlink ....3FB0: buf: ....ADE0 pos:....3FC0 last:....3FC9 file_pos:0 file_last:0 start:....3FC0 end:....3FC9 tag:000055D260A4A880 file:0000000000000000 temporary:1 memory:0 mmap:0 recycled:0 in_file:0 flush:1 last_buf:0 last_in_chain:0 temp_file:0
>
> (I'm copying the tag and the flush bit from the original chain
> in the hopes of it doing something, but no dice).
Note that copying tags is generally wrong. Tags are used to
identify buffers owned by a module, and wrong tag may result in
incorrect behaviour if a module will try to modify/reuse such
buffer. I don't think this can be a problem in your particular
case, yet it's something to avoid.
> When I turn debug mode on logs are a little confusing as well;
> for the incoming chain:
>
> 2022/01/10 10:03:30 [info] 24#24: *5 MD: IN chainlink ....7C00: buf: ....7C10 pos:....91E0 last:....91E9 file_pos:0 file_last:0 start:0000000000000000 end:0000000000000000 tag:000055928B63E880 file:0000000000000000 temporary:1 memory:0 mmap:0 recycled:0 in_file:0 flush:1 last_buf:0 last_in_chain:0 temp_file:0
> <my processing>
> 2022/01/10 10:03:30 [info] 24#24: *5 MD: OUT chainlink ....7C60: buf: ....EA70 pos:....7C70 last:....7C79 file_pos:0 file_last:0 start:.....7C70 end:.....7C79 tag:000055928B63E880 file:0000000000000000 temporary:1 memory:0 mmap:0 recycled:0 in_file:0 flush:1 last_buf:0 last_in_chain:0 temp_file:0
> 2022/01/10 10:03:30 [debug] 24#24: *5 write new buf t:1 f:0 00007FFB71B57C70, pos 00007FFB71B57C70, size: 9 file: 0, size: 0
> 2022/01/10 10:03:30 [debug] 24#24: *5 stream write filter: l:0 f:1 s:9
> 2022/01/10 10:03:30 [debug] 24#24: *5 writev: 9 of 9
> 2022/01/10 10:03:30 [debug] 24#24: *5 stream write filter 0000000000000000
> 2022/01/10 10:03:30 [debug] 24#24: *5 event timer: 4, old: 515169565, new: 515169565
Writing of your buffer is done here. Following lines correspond
to the next chunk of data:
> 2022/01/10 10:03:30 [debug] 24#24: *5 recv: eof:0, avail:-1
> 2022/01/10 10:03:30 [debug] 24#24: *5 recv: fd:12 61 of 16384
> 2022/01/10 10:03:30 [debug] 24#24: *5 write new buf t:1 f:0 0000000000000000, pos 00007FFB70AADC10, size: 61 file: 0, size: 0
> 2022/01/10 10:03:30 [debug] 24#24: *5 stream write filter: l:0 f:1 s:61
> 2022/01/10 10:03:30 [debug] 24#24: *5 SSL to write: 61
> 2022/01/10 10:03:30 [debug] 24#24: *5 SSL_write: 61
> 2022/01/10 10:03:30 [debug] 24#24: *5 stream write filter 0000000000000000
> 2022/01/10 10:03:30 [debug] 24#24: *5 event timer: 4, old: 515169565, new: 515169665
(As far as I understand, this is a chunk of data in the opposite
direction: note it uses SSL_write() instead of writev().)
And here is another call of the stream write filter, which results
in the error:
> 2022/01/10 10:03:30 [debug] 24#24: *5 stream write filter: l:0 f:0 s:0
> 2022/01/10 10:03:30 [alert] 24#24: *5 the stream output chain is empty
Given no read operations before the call, most likely it's called
again by nginx because you haven't correctly marked original
buffers as sent.
> Am I missing some step somewhere that's causing this to fail?
> Does anyone have an example of a simple stream filter module
> which repackages buffers?
Some example of a stream filter module can be found in njs code,
see here:
http://hg.nginx.org/njs/file/9b112a44e540/nginx/ngx_stream_js_module.c#l585
Note the "ctx->buf->pos = ctx->buf->last;" line, which marks the
original buffer as fully sent:
http://hg.nginx.org/njs/file/9b112a44e540/nginx/ngx_stream_js_module.c#l648
Hope this helps.
--
Maxim Dounin
http://mdounin.ru/
_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel
