slact
503 error after 5 sec of waiting on publishing with redis enabled
Trying to publish with command:
curl --request POST --data "test" -H "Accept: text/json" http://example.org/chan/test
Getting 503 error after exactly of 5 seconds waiting:
2017/08/08 16:09:06 [error] 7335#7335: *24132 nchan: error publishing message (HTTP status code 503), client: 127.0.0.1, server: example.org, request: "POST /chan/test HTTP/1.1", host: "example.org"
Reload or restart doesn't help. Sometimes one of requests goes through but every other fails.
My config:
nchan_redis_url "redis://127.0.0.1:6379";
nchan_shared_memory_size 256m;
nchan_message_timeout 3h;
...
location ~ ^/chan/([\w\d\-_:/\.]+)$ {
nchan_pubsub;
nchan_use_redis on;
nchan_websocket_ping_interval 10s;
nchan_message_buffer_length 0;
nchan_channel_id $1;
}
If i comment lines with redis it works OK.
nchan version 1.1.7 nginx -V:
nginx version: nginx/1.11.10
built by gcc 4.9.2 (Debian 4.9.2-10)
built with OpenSSL 1.0.2k 26 Jan 2017
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fstack-protector-strong -Wformat -Werror=format-security -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-z,relro -Wl,-z,now -Wl,-rpath,/usr/local/luajit20/lib/' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --modules-path=/usr/lib/nginx/modules --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-debug --with-pcre-jit --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_v2_module --with-http_dav_module --with-file-aio --with-threads --with-http_addition_module --with-http_flv_module --with-http_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_mp4_module --with-http_random_index_module --with-http_secure_link_module --with-http_sub_module --with-http_xslt_module=dynamic --with-mail=dynamic --with-mail_ssl_module --with-stream=dynamic --with-stream_ssl_module --add-module=/usr/src/lua-nginx-module-0.10.7/ --add-module=/usr/src/nchan-1.1.7/ --add-module=/usr/src/ngx_devel_kit-master/ --add-module=/usr/src/nginx-push-stream-module-master/
Are there any other error messages in the Nginx error log? (Try setting the log level to notice for more info)
What is the output of redis-cli monitor when publishing a message?
Assuming you've addressed the issue, as I have received no additional information. Chances are, Nchan was unable to connect to the Redis server. This usually generates errors in the error log:
2017/09/24 14:34:17 [error] 14962#0: nchan: Can't connect to redis at redis://127.0.0.1:6379: Connection refused.
@slact Sorry for silence, problem still persists. I tried monitor redis and it is shows tha everything is OK, SETEX was processed:
"SETEX" "sockets:e5f7c3cca23251fb7394c060c18abbc1:5" "3600" "a:3:{s:4:\"type\";s:15:\"comment created\"....
nginx error log (notice level) shows only this
2017/10/13 13:56:44 [error] 16536#16536: *25 nchan: error publishing message (HTTP status code 503)
That SETEX has nothing to do with Nchan. You should be seeing EVAL or EVALSHA commands in your log. For example a MONITOR output for message publishing might look like this:
1507948919.863670 [0 127.0.0.1:39800] "EVALSHA" "c7abd99d4fb2717fb1f3b16013baa778fe0a0828" "0" "" "test/foo" "1507948919" "beep" "" "" "1200" "200" "5120"
1507948919.863709 [0 lua] "TIME"
1507948919.863723 [0 lua] "echo" " ####### PUBLISH ######## "
1507948919.863754 [0 lua] "EXISTS" "{channel:test/foo}"
1507948919.863762 [0 lua] "EXISTS" "{channel:test/foo}:msg:1507948919:0"
1507948919.863767 [0 lua] "HSET" "{channel:test/foo}" "current_message" "1507948919:0"
1507948919.863780 [0 lua] "HSET" "{channel:test/foo}" "time" "1507948919"
1507948919.863786 [0 lua] "HSET" "{channel:test/foo}" "max_stored_messages" "200"
1507948919.863801 [0 lua] "HMSET" "{channel:test/foo}:msg:1507948919:0" "content_type" "" "id" "1507948919:0" "data" "beep" "prev_tag" "0" "time" "1507948919" "eventsource_event" "" "prev_time" "0" "ttl" "1200" "tag" "0"
1507948919.863816 [0 lua] "LLEN" "{channel:test/foo}:messages"
1507948919.863821 [0 lua] "LPUSH" "{channel:test/foo}:messages" "1507948919:0"
1507948919.863828 [0 lua] "LRANGE" "{channel:test/foo}:messages" "200" "0"
1507948919.863835 [0 lua] "LTRIM" "{channel:test/foo}:messages" "0" "199"
1507948919.863840 [0 lua] "lindex" "{channel:test/foo}:messages" "-1"
1507948919.863845 [0 lua] "exists" "{channel:test/foo}:msg:1507948919:0"
1507948919.863850 [0 lua] "TTL" "{channel:test/foo}"
1507948919.863853 [0 lua] "EXPIRE" "{channel:test/foo}:msg:1507948919:0" "1200"
1507948919.863859 [0 lua] "EXPIRE" "{channel:test/foo}" "1200"
1507948919.863862 [0 lua] "EXPIRE" "{channel:test/foo}:messages" "1200"
1507948919.863867 [0 lua] "EXPIRE" "{channel:test/foo}:subscribers" "1200"
1507948919.863873 [0 lua] "PUBSUB" "NUMSUB" "{channel:test/foo}:pubsub"
1507948919.863878 [0 lua] "llen" "{channel:test/foo}:messages"
I still think Nchan is unable to connect to Redis. To be sure, add a top-level error log (first few lines in nginx config, before any http {} or server {} blocks) like so:
error_log /path/to/logfile.log notice;
After adding the root-level error_log it's like only 1/10 requests to sockets are getting 503 with the same error in usual log nchan: error publishing message (HTTP status code 503) but with the silence in root-level logfile.
At the very beginning I saw nchan: Established connection to redis at redis://127.0.0.1:6379/3. and in monitor I see the KEEPALIVE messages, so the connection to redis is OK
Ok, in order to figure this out, I'm going to need to look at your servers. Email me at [email protected] to set this up.
OK, I'll write you later when I will get up new server from scratch with that problem.
I'm seeing the same problem as described when using redis. Not sure if there's any updated info on this.
