fix(cli) stop redirecting output when not starting as a daemon #3297

Tieske · 2018-03-14T19:24:12Z

redirecting the nginx start command to temp files will slowly
fill the disk when the process is not started as a daemon.

Initial attempt. Please review carefully, I might not have gotten potential side effects completely covered.

Reference code: pl.utils.execute() and pl.utils.executeex()

Issues resolved

Fix https://discuss.konghq.com/t/stdout-stderr-being-redirected-to-tmp/505

hishamhm · 2018-03-14T19:52:19Z

kong/cmd/utils/nginx_signals.lua

+  else
+    -- not as a dameon, so we cannot redirect because in long running processes
+    -- the output will fill the disk. Use "execute" without redirection instead.
+    local ok, retcode = pl_utils.execute(cmd)


Since we only target one Lua version (LuaJIT), there's no need to use pl_utils.execute here, one can just use os.execute directly (and handle the Lua 5.1 semantics of the results).

I know, but since we use PL everywhere, I'd rather stay consistent. Lmk if you want me to change it.

Not a blocker by any means -- I just noted the added cognitive step (I had to look into Penlight to check if utils.execute did anything else surprising like executeex does; I wouldn't have to if it was os.execute)

@hisham How about any side effects? I'm not very familiar with the underlying unix structures (was surprised by the bug at all), so that's what I'm mostly concerned about.

@hishamhm

Not a blocker by any means -- I just noted the added cognitive step (I had to look into Penlight to check if utils.execute did anything else surprising like executeex does; I wouldn't have to if it was os.execute)

Had to go look for it, see this PR by @bungle . We had issues before. We only support LuaJIT, but that behaves differently based on the 52 compat-flag (compile time).

So we learned the hard way (but apparently not hard enough since I didn't remember 😄 ).

Agreed - better to keep pl_utils.execute, the compat flag was a nightmare to get out of...

We should be adding a test for the foreground mode, asserting that we see Nginx's stdout/stderr logs...

hutchic

ps aux
PID   USER     TIME   COMMAND
    1 root       0:00 nginx: master process /usr/local/openresty/nginx/sbin/nginx -c /usr/local/kong/nginx.conf -p /usr/local/kong/
   46 nobody     0:00 nginx: worker process
   47 nobody     0:00 nginx: worker process
   48 root       0:00 /bin/sh
   53 root       0:00 ps aux

LGTM

thibaultcha · 2018-03-14T21:38:53Z

kong/cmd/utils/nginx_signals.lua

+  if kong_conf.nginx_daemon == "on" then
+    -- running as daemon, so we capture command output to temp files using
+    -- the "executeex" method
+    local ok, _, _, stderr = pl_utils.executeex(cmd)


Just below this line, should print the stdout of nginx? Either here or in the not ok path. The rationale would be to give a more "native" feeling to the user (with print, not with log), so the output looks barefeet from nginx itself. What do you think?

Probably not - if we're running in daemon mode, let's stay consistent with today's behavior, little value in this.

Tieske · 2018-03-22T15:39:32Z

@thibaultcha so adding the test proved to be a painful process. @hishamhm provided some help to figure out exactly how to test it.

Additional info on the underlying problem: it only happens when the nginx log output is directed to stdout/stderr, in which case the full log output is swallowed by the tempfiles created by the kong start command when it starts the underlying nginx.

Please have a look, and let me know any issues.

hishamhm · 2018-03-23T13:51:47Z

spec/02-integration/02-cmd/02-start_stop_spec.lua

+    of the nginx logs. Instead of them being swallowed by the intermediary
+    nginx start command (used by "kong start" under the hood).
+    --]]
+    local xos = _G.os  -- trick the linter here in accepting global updates


instead of tricking LuaCheck, you can use the special comment -- luacheck: ignore (or preferrably a more specific one as specified here: http://luacheck.readthedocs.io/en/stable/inline.html )

k thx, will look into it

biggest issue for now is the test not passing CI. Needs a better way, ideas anyone?

This week @kikito mentioned issues with creating temporary files on Travis, but I never experienced that myself (one of my tests does create a temp file). Any idea on what's causing it to fail?

hmmm looking at it again, it changed. Initially it timedout while waiting for Kong to start, but now also seeing other errors. Probably on the merged branch, since the config properties changed.

I'll rebase first

hishamhm · 2018-03-23T13:53:44Z

spec/02-integration/02-cmd/02-start_stop_spec.lua

+      end
+      local res = assert(admin_client:send {
+        method = "POST",
+        path = "/apis",


0.13 is released! :) we shouldn't use the deprecated /apis entity in new tests

Yes noticed that too.

hishamhm · 2018-03-23T14:40:42Z

spec/02-integration/02-cmd/02-start_stop_spec.lua

+    -- and insert new ones for us to track
+    start_cmd = start_cmd:match("^(.- bin/kong start).-$")
+    start_cmd = start_cmd .. " > " .. stdout .. " 2> " .. stderr
+    start_cmd = start_cmd .. " &"  -- run it detached


I wonder if would it make sense to add a feature in helpers.start_kong to make it do that, instead of making the test rely on knowledge of its internals.

we have that, but it runs Kong as a daemon. And in this case we cannot use that since we run in foreground, and then that call would block, stopping the tests.

I meant adding a flag to start_kong that adds the redirects and &... but at this point I'm still wondering if it's all worth it. As we discussed earlier, this is probably going to remain a fragile test for a very edge case... Would like to hear more opinions!

I think the following test case is a lot more concise and reliable:

it("#oo", function() local pl_utils = require "pl.utils" local pl_file = require "pl.file" local stdout_path = os.tmpname() finally(function() os.remove(stdout_path) end) local cmd = string.format("KONG_PROXY_ACCESS_LOG=/dev/stdout " .. "KONG_NGINX_DAEMON=off %s start -c %s " .. ">%s 2>/dev/null &", helpers.bin_path, helpers.test_conf_path, stdout_path) local ok, _, _, stderr = pl_utils.executeex(cmd) if not ok then error(stderr) end do local proxy_client -- get a connection, retry until kong starts helpers.wait_until(function() proxy_client = helpers.proxy_client() return true end) local res = assert(proxy_client:send { method = "GET", path = "/hello", }) assert.res_status(404, res) -- no API configured end assert(helpers.stop_kong(helpers.test_conf.prefix)) -- TEST: since nginx started in the foreground, the 'kong start' command -- stdout should receive all of nginx's stdout as well. local stdout = pl_file.read(stdout_path) assert.matches([["GET /hello HTTP/1.1" 404]] , stdout, nil, true) end)

Yes, I like this a lot better!

redirecting the nginx start command to temp files will slowly fill the disk when the process is not started as a daemon.

thibaultcha · 2018-03-29T22:24:45Z

Manually merged with the updated test and more descriptive commit message. Thanks!

The previous behavior (which was the same for both nginx_daemon = on|off) was to call 'pl_utils.executeex()', which redirects stdout/stderr to tmp files. When nginx is configured with logs doing to /dev/stdout+/dev/stderr, and nginx_daemon = off, then those files will receive all output. Which brings two issues: 1. the output is hidden from the 'kong start' stdout/stderr, which is not the expected behavior 2. the tmp files will slowly grow and fill up the disk space - they also cannot be rotated From #3297 Signed-off-by: Thibault Charbonnier <thibaultcha@me.com>

Tieske · 2018-03-30T08:15:21Z

hmmm... too quick imo.

I don't like this part:

    local cmd = string.format("KONG_PROXY_ACCESS_LOG=/dev/stdout "    ..
                              "KONG_NGINX_DAEMON=off %s start -c %s " ..
                              ">%s 2>/dev/null &", helpers.bin_path,
                              helpers.test_conf_path, stdout_path)

since it bypasses the recent changes that allow to unset existing enviornment variables etc. to make the tests more reliable.

Let's leave it for now, we can always fix it if it turns out to be a problem later.

The previous behavior (which was the same for both nginx_daemon = on|off) was to call 'pl_utils.executeex()', which redirects stdout/stderr to tmp files. When nginx is configured with logs doing to /dev/stdout+/dev/stderr, and nginx_daemon = off, then those files will receive all output. Which brings two issues: 1. the output is hidden from the 'kong start' stdout/stderr, which is not the expected behavior 2. the tmp files will slowly grow and fill up the disk space - they also cannot be rotated From Kong#3297 Signed-off-by: Thibault Charbonnier <thibaultcha@me.com>

Tieske added the pr/status/please review label Mar 14, 2018

hishamhm reviewed Mar 14, 2018

View reviewed changes

hutchic approved these changes Mar 14, 2018

View reviewed changes

thibaultcha reviewed Mar 14, 2018

View reviewed changes

Tieske force-pushed the fix/no-daemon-no-redirect branch 2 times, most recently from 995c62f to 369f879 Compare March 22, 2018 15:34

Tieske added pr/please review and removed pr/changes requested Changes were requested to this PR by a maintainer. Please address them and ping back once done. labels Mar 22, 2018

Tieske force-pushed the fix/no-daemon-no-redirect branch from 369f879 to 31c7cd6 Compare March 23, 2018 13:07

hishamhm reviewed Mar 23, 2018

View reviewed changes

fix(cli) stop redirecting output when not starting as a daemon

3182bbb

redirecting the nginx start command to temp files will slowly fill the disk when the process is not started as a daemon.

Tieske force-pushed the fix/no-daemon-no-redirect branch 2 times, most recently from 3aaae27 to 1397742 Compare March 23, 2018 15:55

tests(cli) added a test

ac14efd

Tieske force-pushed the fix/no-daemon-no-redirect branch from 1397742 to ac14efd Compare March 23, 2018 15:57

thibaultcha closed this Mar 29, 2018

thibaultcha deleted the fix/no-daemon-no-redirect branch March 29, 2018 22:24

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix(cli) stop redirecting output when not starting as a daemon #3297

fix(cli) stop redirecting output when not starting as a daemon #3297

Tieske commented Mar 14, 2018

hishamhm Mar 14, 2018

Tieske Mar 14, 2018

hishamhm Mar 14, 2018

Tieske Mar 14, 2018

Tieske Mar 14, 2018

thibaultcha Mar 14, 2018

hutchic left a comment

thibaultcha Mar 14, 2018

thibaultcha Mar 15, 2018

Tieske commented Mar 22, 2018

hishamhm Mar 23, 2018

Tieske Mar 23, 2018

hishamhm Mar 23, 2018

Tieske Mar 23, 2018

hishamhm Mar 23, 2018

Tieske Mar 23, 2018

hishamhm Mar 23, 2018

Tieske Mar 23, 2018

hishamhm Mar 23, 2018

thibaultcha Mar 29, 2018

hishamhm Mar 29, 2018

thibaultcha commented Mar 29, 2018

Tieske commented Mar 30, 2018

fix(cli) stop redirecting output when not starting as a daemon #3297

fix(cli) stop redirecting output when not starting as a daemon #3297

Conversation

Tieske commented Mar 14, 2018

Issues resolved

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hutchic left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Tieske commented Mar 22, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

thibaultcha commented Mar 29, 2018

Tieske commented Mar 30, 2018