0

I'm trying to get Nginx (running as a Kubernetes ingress controller) to log in milliseconds rather then seconds. (This is so we can ingest the logs into our existing Elasticsearch system, which already has other systems logging in ms)

Based on this blog post I've tried the following in the 'http' context:

  map $host $request_time_ms {
    default 'test';
  }
  log_by_lua_block { 
    ngx.var.request_time_ms = 'foo'
  }

And then in my log string:

 '{...."duration_ms":"$request_time_ms",....}'

But the logged value is always the default value of test rather than the expected one of foo.

Ultimately it should end up like:

ngx.var.request_time_ms = math.floor(tonumber(ngx.var.request_time) * 1000)

But I'm just trying to get the basic situation to work first.

Any idea why this doesn't work? It's as if the log_by_lua_block just isn't running.

Mark
  • 165
  • 1
  • 5

1 Answers1

0

I can't reproduce your situation on my own server (need to say I din't use kubernetes or docker for tests). For me this configuration works as expected. It is really looks like log_by_lua_block isn't running at all on your ingress controller. But you can use a following workaround to get request time in milliseconds rather than seconds:

map $request_time $request_time_ms {
    ~^0\.0*(\d+?)$  $1;
    ~(\d+)\.(\d+)   $1$2;
}
Ivan Shatsky
  • 2,360
  • 2
  • 6
  • 17
  • This seems to work, but I've also had some values come through as: ` "duration":0.112, "duration_ms":"8"` which is weird.... – Mark Sep 24 '21 at 15:48
  • It is really looks weird, but I don't have an answer why it is happening... – Ivan Shatsky Sep 24 '21 at 18:32
  • Of course most probably it's too late, but a few days ago I figured a new `map` option that I wasn't aware of at the time of writing the answer - a `volatile` keyword. I wonder if it could help at this case. – Ivan Shatsky Jun 12 '22 at 17:52