Using vars multiple times in access_log.format does not work correctly with njs

[valtzu]

Related to recently added feature #1024.

---

When using NJS-based access log format (with Docker unit 1.32.0), the value of first vars is used for all the rest vars – see the example below.

Config

{
  "access_log": {
    "path": "/dev/stderr",
    "format": "`${JSON.stringify({bodyLength:vars.body_bytes_sent,status:vars.status})}\n`"
  }
}

or

  "format": "`{bodyLength:\"${vars.body_bytes_sent}\",status:\"${vars.status}\"}\n`"

Log output:

unit-1  | {"bodyLength":"82733","status":"82733"}

---

Whereas with non-js version "format": "bodyLength=$body_bytes_sent status=$status" it works fine:

unit-1  | bodyLength=82733 status=200

[valtzu]

Actually this behavior seems to be random – sometimes it works, sometimes it doesn't 🤔

unit-1  | {"bodyLength":"82733","status":"82733"}
unit-1  | {"bodyLength":"82735","status":"82735"}
unit-1  | {"bodyLength":"82735","status":"200"}
unit-1  | {"bodyLength":"82735","status":"82735"}
unit-1  | {"bodyLength":"82735","status":"200"}
unit-1  | {"bodyLength":"82736","status":"200"}
unit-1  | {"bodyLength":"82734","status":"200"}
unit-1  | {"bodyLength":"82736","status":"200"}
unit-1  | {"bodyLength":"82736","status":"200"}
unit-1  | {"bodyLength":"82736","status":"200"}
unit-1  | {"bodyLength":"82736","status":"200"}
unit-1  | {"bodyLength":"82736","status":"200"}

[tippexs]

Hi @valtzu Thanks for reaching out! This looks indeed not correct and I was able to reproduce the issue with the latest version of our Docker-Image and the format mentioned above.

We will have a look on this and share our progress here! Thanks again for reaching out!

[hongzhidao]

Hi @valtzu,
Thanks for the reporting. Will fix it soon with the patch.

diff --git a/src/nxt_var.c b/src/nxt_var.c
index 2600371b..57110f66 100644
--- a/src/nxt_var.c
+++ b/src/nxt_var.c
@@ -147,7 +147,7 @@ nxt_var_ref_get(nxt_tstr_state_t *state, nxt_str_t *name, nxt_mp_t *mp)

     if (decl != NULL) {
         ref->handler = decl->handler;
-        ref->cacheable = decl->cacheable;
+        ref->cacheable = (mp == state->pool) ? decl->cacheable : 0;

         goto done;
     }