Debug logging causes memory exception

[wesmi]

After updating to nginx version 1.2.2, a debug log line in njs.d/dns/dns.js looks like it causes a memory exception:

2023/03/18 07:57:25 [error] 1384#1384: *270 js exception: MemoryError while proxying and sending to client, client: 127.0.0.1, server: 127.0.0.1:8053, upstream: "127.0.0.1:7053", bytes from/to client:140/0, bytes from/to upstream:43/27

2023/03/18 07:57:25 [error] 1384#1384: *267 upstream prematurely closed connection while reading response header from upstream, client: 104.244.223.30, server: query.doh.example.org, request: "POST /dns-query HTTP/2.0", upstream: "http://127.0.0.1:8053/dns-query", host: "query.doh.example.org"

After I added several more debug lines to see where the problem happened, I narrowed it down to this:

debug(s, "DNS Res Packet: " + JSON.stringify( Object.entries(packet)) );

(Note that the earlier debug line that dumps packet.answers to the log does work.)

I'm not skilled enough with JavaScript or the Nginx JS module to narrow down further, my apologies. But commenting out this line and making no other changes allows the module to work again. From what little I do know, I don't see an obvious reason why this log line would up and fail.

For context, my DoH setup is based on Scott Helme's instructions to use Nginx + DoH + Pi Hole, extended from the Nginx blog.

[StefanescuCristian]

I don't know why either, but you're correct.

Setting var dns_decode_level = 0; instead of 3 makes the DNS queries work again.

[TuxInvader]

Hi @wesmi - can you tell me what version of NJS you are using please?

Thanks,
Mark

[antkern]

Hello @TuxInvader

I have the same problem using a docker image docker.io/library/nginx:1.21.1 it is perfectly fine.
With a docker.io/library/nginx:1.22.1 it crashes.

The njs version for 1.21.1:

dpkg -s nginx-module-njs
Package: nginx-module-njs
Status: install ok installed
Priority: optional
Section: httpd
Installed-Size: 3928
Maintainer: NGINX Packaging <nginx-packaging@f5.com>
Architecture: amd64
Version: 1.21.1+0.6.1-1~buster
Provides: nginx-module-njs-r1.21.1
Depends: libc6 (>= 2.25), libpcre3, libreadline7 (>= 6.0), nginx-r1.21.1
Description: nginx njs dynamic modules
 njs dynamic modules for nginx
Homepage: https://nginx.org/

./usr/bin/njs -v
0.6.1

The njs version for 1.22.1:

dpkg -s nginx-module-njs
Package: nginx-module-njs
Status: install ok installed
Priority: optional
Section: httpd
Installed-Size: 4740
Maintainer: NGINX Packaging <nginx-packaging@f5.com>
Architecture: amd64
Version: 1.22.1+0.7.11-1~bullseye
Provides: nginx-module-njs-r1.22.1
Depends: libc6 (>= 2.29), libpcre2-8-0 (>= 10.32), libreadline8 (>= 6.0), libssl1.1 (>= 1.1.1), libxml2 (>= 2.7.4), nginx-r1.22.1
Description: nginx njs dynamic modules
 njs dynamic modules for nginx
Homepage: https://nginx.org/

/usr/bin/njs -v
0.7.11

Ant

[wesmi]

Sorry for the delay in replying, I am also on njs 1.22.1:

`
dpkg -s nginx-module-njs

Package: nginx-module-njs

Status: install ok installed

Priority: optional

Section: httpd

Installed-Size: 4846

Maintainer: NGINX Packaging nginx-packaging@f5.com

Architecture: amd64

Version: 1.22.1+0.7.11-1~jammy

Provides: nginx-module-njs-r1.22.1

Depends: libc6 (>= 2.35), libpcre2-8-0 (>= 10.32), libreadline8 (>= 6.0), libssl3 (>= 3.0.0~~alpha1), libxml2 (>= 2.7.4), nginx-r1.22.1

Description: nginx njs dynamic modules

njs dynamic modules for nginx

Homepage: https://nginx.org/
`

[TuxInvader]

This was caused by the packet object containing the binary DNS packet inside packet.data.
I've added a new $dns_debug_level variable so that debugging can be enabled at decode levels lower than 3 (max). If the packet is going to be logged, then I delete the data entry from packet before logging it.

See e04a8d7