Tasks appear to freeze using Nginx as a frontend.

[bugz8unny69]

Hi,

When I run a task, tasks will remain in the waiting state and never reach the running state. This is the case when having Nginx as a reverse proxy to Semaphore.

nginx.conf

worker_processes auto;
error_log /var/log/nginx/error.log;
pid /run/nginx.pid;

events {
    worker_connections 1024;
}

http {
    log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for"';

    access_log  /var/log/nginx/access.log  main;

    sendfile            on;
    tcp_nopush          on;
    tcp_nodelay         on;
    keepalive_timeout   65;
    types_hash_max_size 2048;

    include             /etc/nginx/mime.types;
    default_type        application/octet-stream;

    # Load modular configuration files from the /etc/nginx/conf.d directory.
    # See http://nginx.org/en/docs/ngx_core_module.html#include
    # for more information.
    include /etc/nginx/conf.d/*.conf;

    server {
        listen       80 default_server;
        listen       [::]:80 default_server;
        server_name  _;
        root         /usr/share/nginx/html;

        # Load configuration files for the default server block.
        include /etc/nginx/default.d/*.conf;

        location / {
                        proxy_set_header Host            $host;
                        proxy_set_header X-Real-IP       $remote_addr;
                        proxy_set_header X-Forwared-For  $proxy_add_x_forwarded_for;
                        proxy_pass http://10.0.0.14:3000;
        }

        error_page 404 /404.html;
            location = /40x.html {
        }

        error_page 500 502 503 504 /50x.html;
            location = /50x.html {
        }
    }
}

_semaphoreconfig.json

{
        "mysql": {
                "host": "10.0.0.9:3306",
                "user": "ansible_usr",
                "pass": "[redacted]",
                "name": "ansible_db"
        },
        "port": "",
        "bugsnag_key": "",
        "tmp_path": "/tmp/semaphore",
        "cookie_hash": "[redacted]",
        "cookie_encryption": "[redacted]"
 }

Attempting to debug the issue using Firefox Developer network tool, I see a lot of WebSockets failing with 400 Bad Request to /api/ws. See HTTP headers below:

Request Headers

Host: ansible.lhprojects.int
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:47.0) Gecko/20100101 Firefox/47.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip, deflate
DNT: 1
Sec-WebSocket-Version: 13
Origin: http://ansible.lhprojects.int
Sec-WebSocket-Extensions: permessage-deflate
Sec-WebSocket-Key: NFyjXxKr7WJ7Ns5hzpBGiA==
Cookie: semaphore=MTQ2OTMzMTgwMHxfOWV3anNoRWEzWDd6UmxGMk51RjMtUWxRaEZGdndpU1FIcC0wdGtRRjRzblNxQkFZY2NrXzQtUkVlTDh6V1VvR0FuR1FUTkI3cS1JSUJlRWM4QmkxdDg9fBOpfKqsOiyK4sDLOS_fqrCUonwHQH-8gmsLFq5pEHYy
Connection: keep-alive, Upgrade
Pragma: no-cache
Cache-Control: no-cache
Upgrade: websocket

Response Headers HTTP 400 Bad Request

Connection: keep-alive
Content-Length: 12
Content-Type: text/plain; charset=utf-8
Date: Sun, 24 Jul 2016 04:28:36 GMT
Server: nginx/1.6.3
X-Content-Type-Options: nosniff

Since your Installation Wiki does state that reverse proxies are supported, I must be doing something wrong here?

Edit1: Here is a copy of the Semaphore log

Jul 24 06:32:55 ansible semaphore: 2016/07/24 06:32:55 bugsnag.Notify: not notifying in development
Jul 24 06:32:55 ansible semaphore: #033[31m2016/07/24 06:32:55 [Recovery] panic recovered:
Jul 24 06:32:55 ansible semaphore: GET /api/ws HTTP/1.0
Jul 24 06:32:55 ansible semaphore: Host: ansible.lhprojects.int
Jul 24 06:32:55 ansible semaphore: Connection: close
Jul 24 06:32:55 ansible semaphore: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Jul 24 06:32:55 ansible semaphore: Accept-Encoding: gzip, deflate
Jul 24 06:32:55 ansible semaphore: Accept-Language: en-US,en;q=0.5
Jul 24 06:32:55 ansible semaphore: Cache-Control: no-cache
Jul 24 06:32:55 ansible semaphore: Connection: close
Jul 24 06:32:55 ansible semaphore: Cookie: semaphore=MTQ2OTMzMTgwMHxfOWV3anNoRWEzWDd6UmxGMk51RjMtUWxRaEZGdndpU1FIcC0wdGtRRjRzblNxQkFZY2NrXzQtUkVlTDh6V1VvR0FuR1FUTkI3cS1JSUJlRWM4QmkxdDg9fBOpfKqsOiyK4sDLOS_fqrCUonwHQH-8gmsLFq5pEHYy
Jul 24 06:32:55 ansible semaphore: Dnt: 1
Jul 24 06:32:55 ansible semaphore: Origin: http://ansible.lhprojects.int
Jul 24 06:32:55 ansible semaphore: Pragma: no-cache
Jul 24 06:32:55 ansible semaphore: Sec-Websocket-Extensions: permessage-deflate
Jul 24 06:32:55 ansible semaphore: Sec-Websocket-Key: QDTShBwPzdMe736+4fJuEg==
Jul 24 06:32:55 ansible semaphore: Sec-Websocket-Version: 13
Jul 24 06:32:55 ansible semaphore: User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:47.0) Gecko/20100101 Firefox/47.0
Jul 24 06:32:55 ansible semaphore: X-Forwared-For: 10.0.0.41
Jul 24 06:32:55 ansible semaphore: X-Real-Ip: 10.0.0.41
Jul 24 06:32:55 ansible semaphore: websocket: could not find connection header with token 'upgrade'
Jul 24 06:32:55 ansible semaphore: /usr/local/Cellar/go/1.6/libexec/src/runtime/panic.go:426 (0x42de89)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/bugsnag/bugsnag-go/bugsnag.go:52 (0x534831)
Jul 24 06:32:55 ansible semaphore: /usr/local/Cellar/go/1.6/libexec/src/runtime/asm_amd64.s:472 (0x45d17e)
Jul 24 06:32:55 ansible semaphore: /usr/local/Cellar/go/1.6/libexec/src/runtime/panic.go:426 (0x42de89)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/ansible-semaphore/semaphore/api/sockets/handler.go:102 (0x4ce12b)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/context.go:97 (0x53d8ea)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/logger.go:66 (0x54f21a)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/context.go:97 (0x53d8ea)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/Projects/semaphore/cli/main.go:72 (0x401aef)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/context.go:97 (0x53d8ea)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/recovery.go:45 (0x54ff81)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/context.go:97 (0x53d8ea)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/gin.go:284 (0x544542)
Jul 24 06:32:55 ansible semaphore: /Users/m/p/gospace/src/github.com/gin-gonic/gin/gin.go:265 (0x544177)
Jul 24 06:32:55 ansible semaphore: /usr/local/Cellar/go/1.6/libexec/src/net/http/server.go:2081 (0x61e44e)
Jul 24 06:32:55 ansible semaphore: /usr/local/Cellar/go/1.6/libexec/src/net/http/server.go:1472 (0x61acfe)
Jul 24 06:32:55 ansible semaphore: /usr/local/Cellar/go/1.6/libexec/src/runtime/asm_amd64.s:1998 (0x45f831)
Jul 24 06:32:55 ansible semaphore: #033[0m
Jul 24 06:32:55 ansible semaphore: [GIN-debug] [WARNING] Headers were already written. Wanted to override status code 400 with 500

At first glance, Nginx might be stripping is not sending the HTTP Upgrade: websocket header. I am looking further into it. See Nginx Websockets. I need to explicitly forward the Upgrade: websocket header to Semaphore.

This partially fixes the issue, I get output information, unfortunately the status still remains in the waiting state while the task is running. Started and Ended are only updated after the completion of the task.

[haoxinglu]

@lhorace I'm having the same issue here. The Task Log is not updated. When I toggle the "Raw Output" option, the task log can be updated. Do we have any updates to fully fix this issue? Thank you so much.

PS: I didn't see this issue when I run the Semaphore in docker.

[matejkramny]

The task log uses websockets to receive new data. Can you check your browser's logs if this is the case?

[haoxinglu]

@matejkramny I do saw a lot of websocket errors in my browser's console log. WebSocket connection to 'ws://host:3000/api/ws' failed: Error during WebSocket handshake: Unexpected response code: 403 And it keeps retrying.

[matejkramny]

Is there anything that could prevent a websocket connection such as running the website on https or using reverse-proxies such as nginx?

[haoxinglu]

@matejkramny It seems like I'm running on http and I don't have nginx running on my server. Hmm...

[matejkramny]

Hmm that's strange.. Try logging out & back in and check the cookies get sent with the websocket request.

[bugz8unny69]

You don't have anything in between the browser and the webserver? If no, what webserver are you using? Check the logs, it may not explicitly say why it 403 in detail, you may have to increase logging. 403 is often due to Access Rules. If is the web server is the responsible for the 403 and not Semphore (software). As @matejkramny mentioned, cookies could be the cause as well.

In regards to the question, I haven't use Semphore in quite awhile now, and there have been changes to code.

[haoxinglu]

@matejkramny @lhorace Thank you very much for both of you. I asked a few of my colleagues to test the semaphore for me and some of them can actually see the Task logs have been updated. So I begin to think it's my browser or network issue.

[matejkramny]

hey @lhorace, sorry for spamming your inbox :P

@haoxinglu please open a new issue

[bugz8unny69]

@matejkramny Not a problem at all! I am getting around to updating Semphore :)