curl: (7) couldn't connect to host

[melv1n]

Running both redis and pushd.coffee as background processes. I was trying some curl commands from the doc. The first command responds normal and the second gives 'curl: (7) couldn't connect to host'. I see that the process just has stopped working.

The trace gives: select(6, [3 5], [], NULL, NULL) = ? ERESTARTNOHAND (To be restarted) --- SIGCHLD (Child exited) @ 0 (0) --- write(6, "\21", 1) = 1 rt_sigreturn(0x6) = -1 EINTR (Interrupted system call) select(6, [3 5], [], NULL, NULL) = 1 (in [5]) read(5, "\21", 1) = 1 wait4(3250, [{WIFEXITED(s) && WEXITSTATUS(s) == 8}], WNOHANG|WSTOPPED, NULL) = 3250 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 getuid() = 0 sendto(7, "<86>May 24 22:29:47 sudo: pam_un"..., 78, MSG_NOSIGNAL, NULL, 0) = 78 munmap(0x7f16620f9000, 2109656) = 0 munmap(0x7f1661edf000, 2200480) = 0 munmap(0x7f1661ca6000, 2327040) = 0 munmap(0x7f1661a87000, 2221680) = 0 munmap(0x7f1661885000, 2101280) = 0 munmap(0x7f1661683000, 2101296) = 0 munmap(0x7f1661480000, 2105560) = 0 exit_group(8) = ?

What is causing this problem?

[melv1n]

Found the problem. It has to do with console logging. The cause lies with the console logging which it's expecting. When you start pushd in console, put as a background process and kill the terminal session, both pushd.coffee as well ass the node process go down after the first request.

It expects the console log to be there. By killing the console session, that log is gone. So it can't write to that log and both traces on node and pushd process go haywire and both processes are killed.

The workaround is to start pushd without going down, is by saying where to write the logs to and throw pushd in a background process: ./server.js 1>ok.out 2>err.out &

Hope this logging issue can be fixed, but the command above is the best workaround and pushd will run as advertised.

[jvah]

Hmm, I wonder if this is a pushd issue or a Node.js issue, should check it out...

[melv1n]

This is the debug trace for the node /usr/bin/coffee pushd.coffee process. This whole trace is from performing the first curl (and only) curl command after you start pushd via normal command, put it in background, end console session, start new console session and execute that curl command:

Process attached - interrupt to quit clock_gettime(CLOCK_MONOTONIC, {5759, 250874746}) = 0 epoll_wait(5, {{EPOLLIN, {u32=12, u64=12}}}, 1024, 3533868) = 1 clock_gettime(CLOCK_MONOTONIC, {5803, 640751944}) = 0 accept4(12, 0, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = 10 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 gettimeofday({1369484260, 348862}, NULL) = 0 accept4(12, 0, NULL, SOCK_CLOEXEC|SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) clock_gettime(CLOCK_MONOTONIC, {5803, 643149837}) = 0 epoll_ctl(5, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 epoll_wait(5, {{EPOLLIN, {u32=10, u64=10}}}, 1024, 119997) = 1 clock_gettime(CLOCK_MONOTONIC, {5803, 643507703}) = 0 read(10, "POST /subscriber/J8lHY4X1XkU HTT"..., 65536) = 268 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 gettimeofday({1369484260, 350291}, NULL) = 0 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 gettimeofday({1369484260, 355252}, NULL) = 0 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 gettimeofday({1369484260, 360369}, NULL) = 0 gettimeofday({1369484260, 360857}, NULL) = 0 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 write(14, "_1\r\n$5\r\nMULTI\r\n", 15) = 15 write(14, "_3\r\n$6\r\nzscore\r\n$11\r\nsubscribers"..., 52) = 52 write(14, "_8\r\n$5\r\nhmset\r\n$22\r\nsubscriber:J"..., 110) = 110 write(14, "_1\r\n$4\r\nEXEC\r\n", 14) = 14 clock_gettime(CLOCK_MONOTONIC, {5803, 656714318}) = 0 epoll_ctl(5, EPOLL_CTL_MOD, 14, {EPOLLIN, {u32=14, u64=14}}) = 0 epoll_wait(5, {{EPOLLIN, {u32=14, u64=14}}}, 1024, 119984) = 1 clock_gettime(CLOCK_MONOTONIC, {5803, 657243618}) = 0 read(14, "+OK\r\n+QUEUED\r\n+QUEUED\r\n_2\r\n$-1\r\n"..., 65536) = 37 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 write(14, "_2\r\n$3\r\ndel\r\n$22\r\nsubscriber:J8l"..., 42) = 42 clock_gettime(CLOCK_MONOTONIC, {5803, 658633558}) = 0 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 epoll_ctl(5, EPOLL_CTL_MOD, 14, {EPOLLIN, {u32=14, u64=14}}) = 0 epoll_wait(5, {{EPOLLIN, {u32=14, u64=14}}}, 1024, 119982) = 1 clock_gettime(CLOCK_MONOTONIC, {5803, 659242075}) = 0 read(14, ":1\r\n", 65536) = 4 write(2, "error: No subscriber J8lHY4X1XkU"..., 33) = -1 EIO (Input/output error) futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 gettimeofday({1369484260, 368990}, NULL) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 gettimeofday({1369484260, 370140}, NULL) = 0 gettimeofday({1369484260, 370463}, NULL) = 0 write(10, "HTTP/1.1 404 Not Found\r\nContent-"..., 141) = 141 write(1, "POST /subscriber/J8lHY4X1XkU 404"..., 33) = -1 EIO (Input/output error) clock_gettime(CLOCK_MONOTONIC, {5803, 665286043}) = 0 futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 close(2) = 0 write(2, "\n", 1) = -1 EBADF (Bad file descriptor) futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 write(2, "events.js:72\n", 13) = -1 EBADF (Bad file descriptor) write(2, " throw er; // Unhandled '"..., 45) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, " ", 1) = -1 EBADF (Bad file descriptor) write(2, "^", 1) = -1 EBADF (Bad file descriptor) write(2, "\n", 1) = -1 EBADF (Bad file descriptor) futex(0x7f44580008c8, FUTEX_WAKE_PRIVATE, 1) = 1 write(2, "Error: write EIO\n at errnoExcep"..., 93) = -1 EBADF (Bad file descriptor) futex(0xdebfa4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xdebfa0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0xdebf60, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x7f445eb3a9d0, FUTEX_WAIT, 3521, NULL) = -1 EAGAIN (Resource temporarily unavailable) exit_group(8) = ? Process detached

[melv1n]

Btw. it would be nice if the normal startup (sudo coffee pushd.coffee) would do the same as the command above. Create two logs, one log with confirmed events and one log with error events. Makes it more robust to tail the error part if something goes wrong.

[jvah]

There hasn't been releases since adding the winston logging, so I could still change the winston support to be more configurable. Then you could define in your settings.coffee if you want to put your logs into console, a file, multiple files, some database or whatever.

I don't think running Node.js as root is recommended though, it's usually better to run it as a non-privileged user with some proxy running as root if port 80 is necessary.

[melv1n]

This was in a test environment, production is always non-root. Just wanted to make sure user account stuff didn't matter and testing several versions of node/redis to see what was causing this.

Agree, best would be to make it configurable in settings.coffee and don't have to worry about it. I strongly recommend to let it create two logs out-of-the-box when executing 'sudo coffee pushd.coffee': an 'ok' log and an 'error' log, as displayed in my workaround. The reason for creating two logs, is for tailing error events separate from successful events. So you can oversee and spot issues more easy, instead of pushing both down 1 log. Especially when the volumes are higher.