Modules: release work started while logging unhandled rejections

Context teardown cleared pending events before logging an unhandled
rejection.  Converting the rejection reason to a string runs user code,
which could start a timer or a fetch() after the cleanup.  The timer or
connection then outlived the request pool, resulting in use-after-free
with both engines.

Log unhandled rejections before clearing events.

diff --git a/nginx/ngx_js.c b/nginx/ngx_js.c
index 78cbe5b63845c9d936aa01025abdb6e508ac9edb..a7ec295e02a49e25f586988a306bed8bd4ce2401 100644 (file)
--- a/nginx/ngx_js.c
+++ b/nginx/ngx_js.c
@@ -915,11 +915,16 @@ ngx_engine_njs_destroy(ngx_engine_t *e, ngx_js_ctx_t *ctx,
 
         (void) ngx_njs_execute_pending_jobs(e->u.njs.vm, ctx->log);
 
-        ngx_njs_clear_events(ctx);
+        /*
+         * Logging can run user code that starts asynchronous work,
+         * clearing events after it releases such work.
+         */
 
         if (ngx_js_unhandled_rejection(ctx)) {
             ngx_js_log_exception(e->u.njs.vm, ctx->log, "unhandled rejection");
         }
+
+        ngx_njs_clear_events(ctx);
     }
 
     njs_vm_destroy(e->u.njs.vm);
@@ -1390,14 +1395,19 @@ ngx_engine_qjs_destroy(ngx_engine_t *e, ngx_js_ctx_t *ctx,
             reusable = 0;
         }
 
-        ngx_qjs_clear_events(ctx);
-
         JS_SetHostPromiseRejectionTracker(JS_GetRuntime(cx), NULL, NULL);
 
+        /*
+         * Logging can run user code that starts asynchronous work,
+         * clearing events after it releases such work.
+         */
+
         if (ngx_qjs_unhandled_rejection(ctx)) {
             ngx_qjs_log_exception(e, ctx->log, "unhandled rejection");
         }
 
+        ngx_qjs_clear_events(ctx);
+
         ngx_qjs_detach_ctx(ctx, cx);
 
         if (JS_IsJobPending(JS_GetRuntime(cx))) {

diff --git a/nginx/t/js_teardown.t b/nginx/t/js_teardown.t
new file mode 100644 (file)
index 0000000..f8c2f7a
--- /dev/null
+++ b/nginx/t/js_teardown.t
@@ -0,0 +1,120 @@
+#!/usr/bin/perl
+
+# (C) Dmitry Volyntsev
+# (C) F5, Inc.
+
+# Tests for asynchronous work started by JavaScript code that runs while
+# a context is being destroyed.
+
+###############################################################################
+
+use warnings;
+use strict;
+use Test::More;
+
+BEGIN { use FindBin; chdir($FindBin::Bin); }
+
+use lib 'lib';
+use Test::Nginx;
+
+###############################################################################
+
+select STDERR; $| = 1;
+select STDOUT; $| = 1;
+
+my $t = Test::Nginx->new()->has(qw/http/)
+    ->write_file_expand('nginx.conf', <<'EOF');
+
+%%TEST_GLOBALS%%
+
+daemon off;
+worker_processes 1;
+
+events {
+}
+
+http {
+    %%TEST_GLOBALS_HTTP%%
+
+    js_import test.js;
+
+    server {
+        listen       127.0.0.1:8080;
+        server_name  localhost;
+
+        location /zero {
+            js_context_reuse 0;
+            js_content test.content;
+        }
+
+        location /reuse {
+            js_context_reuse 1;
+            js_content test.content;
+        }
+
+        location /native {
+            return 200 native;
+        }
+    }
+}
+
+EOF
+
+$t->write_file('test.js', <<'EOF');
+    function late(name) {
+        return () => ngx.log(ngx.ERR, 'late ' + name);
+    }
+
+    function content(r) {
+        const mode = r.args.mode;
+
+        if (mode === 'timer') {
+            Promise.reject({toString() {
+                setTimeout(late('rejection timer'), 10);
+                return 'rejection timer reason';
+            }});
+
+        } else if (mode === 'fetch') {
+            Promise.reject({toString() {
+                ngx.fetch('http://127.0.0.1:' + r.variables.server_port
+                          + '/native').then(late('rejection fetch'));
+                return 'rejection fetch reason';
+            }});
+
+        } else if (mode === 'exit') {
+            njs.on('exit', () => {
+                setTimeout(late('exit timer'), 10);
+                ngx.log(ngx.ERR, 'exit hook ' + r.uri);
+            });
+
+        }
+
+        r.return(200, 'ok');
+    }
+
+    export default {content};
+EOF
+
+$t->try_run('no njs available')->plan(9);
+
+###############################################################################
+
+for my $scope ('zero', 'reuse') {
+    for my $mode ('timer', 'fetch', 'exit') {
+        like(http_get("/$scope?mode=$mode"), qr/ok$/, "$scope $mode");
+    }
+}
+
+http_get('/reuse?mode=none') for 1 .. 2;
+select undef, undef, undef, 0.2;
+
+$t->stop();
+
+my $log = $t->read_file('error.log');
+
+like($log, qr/unhandled rejection: rejection fetch reason/,
+    'rejection logged');
+like($log, qr/exit hook \/reuse/, 'exit hook runs');
+unlike($log, qr/late /, 'no teardown work runs later');
+
+###############################################################################