daphne, nginx을 활용한 소켓 통신 연결 삽질 극복기(TroubleShooting)

오늘은 구현했던 실시간 채팅기능을 프로덕션 서버에서 올리다 삽질한 걸 남겨보려 한다.

목차

• 현상
• 세팅했던 설정
• 테스트
• 해결책
• 결론

현상

프로덕션 환경에서 로컬환경에서 세팅한 것과 유사하게

• nginx
• daphne (로컬호스트 8001번 포트와 바인딩했다.)
• redis, channel-redis

설정을 진행하고 브라우저에서 소켓 연결을 시도했다.

그런데 실서버에서 소켓 연결을 하면 자꾸 disconnect이 되었다.

클라이언트가 시도하는 소켓 주소 : wss://www.{도메인 이름}:8001/ws/hole/<str:hole_id>
→ 여기서 hole_id는 변수

소켓 연결을 위해 세팅한 것

삽질을 하면서 1차로 했던 설정은 아래와 같다.

nginx :

• 세팅 파일 : /etc/nginx/sites-enabled/{도메인 이름}

    upstream your_channel_daphne {
        server localhost:8001;
    }
    server {
   	{...}
  
     	 access_log /var/log/nginx/live_be/access.log;
           error_log /var/log/nginx/live_be/error.log;
  
  	server_name {도메인 이름} www.{도메인 이름};
  
      	listen [::]:443 ssl ipv6only=on; # managed by Certbot
      	listen 443 ssl; # managed by Certbot
     	{...}
  
      	location /ws/ {
              proxy_pass http://your_channel_daphne;
  							proxy_http_version 1.1;
              proxy_set_header    Upgrade $http_upgrade;
              proxy_set_header Connection "upgrade";
  							proxy_redirect off;
              proxy_set_header Host $host;
              proxy_set_header X-Real-IP $remote_addr;
              proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
              proxy_set_header X-Forwarded-Host $server_name;
      }
  }

• port : 443 port, 8001 열려있음. AWS EC2 보안그룹에도 열려있음.

django settings 파일 설정 :

• CHANNEL_LAYERS 설정

CHANNEL_LAYERS = {
    "default": {
        "BACKEND": "channels_redis.core.RedisChannelLayer",
        "CONFIG": {
            "hosts": [os.environ.get("REDIS_URL")]
        },
    },
}

REDIS_URL='redis://:{비밀번호}@{redis 있는 서버 public ip}:6379/0'

• ASGI_APPLICATION 설정
  ASGI_APPLICATION = 'config.routing.application'

• asgi.py 파일 설정

import os
import django
# from django.core.asgi import get_asgi_application
from channels.routing import get_default_application
# from channels.asgi import get_channel_layer
os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'config.settings.production')


django.setup()
application = get_default_application()

• routing.py 파일 설정

from django.conf.urls import url
from django.urls import re_path,path
from channels.routing import ProtocolTypeRouter, URLRouter
from channels.auth import AuthMiddlewareStack
# from channels.security.websocket import AllowedHostsOriginValidator, OriginValidator

from chat_messages.consumers import ChatConsumer

websocket_urlpatterns = [
    re_path(r"^ws/hole/(?P<room_id>[\w.@+-]+)", ChatConsumer),
]

application = ProtocolTypeRouter({
    'websocket': AuthMiddlewareStack(
            URLRouter(        
                    websocket_urlpatterns
            )
        )
})

redis 설정 : 다른 서버에 있음. (3.36.64.xx)

• bind : 위의 ip의 private ip, 127.0.0.1로 설정
• auth 걸어놓음.
• daphne가 있는 서버에서 redis-cli로 테스트 해보면 접속 잘 됨.

daphne : ASGI 요청 처리하는 웹소켓 서버

daphne.service로 설정해놓음.

• 현재 : 호스트 + 포트 설정
• socket으로 설정하는 방법도 해봄.
• ssl로 설정하는 방법도 해봄.

3가지 방법 모두 똑같이 안 됨.

gunicorn : HTTP요청 처리하는 서버

• 이거도 nginx에 같이 설정 되어 있는데 여기는 잘 됨.

1차 설정 이후 발생 현상

• 브라우저 콘솔 내용을 보면 socket connection is established 되기 전에 socket이 close 됨. (연결 시도를 계속 하지만 disconnect만 계속 됨.)
• nginx access.log, error.log 혹은 gunicorn access.log, error.log에는 websocket 관련 내용이 기록되지않음.
  • handshaking 시도도 안 함.

혹시나 관련 패키지 버전문제인가 싶어서,

redis가 있는 인스턴스를 ubuntu 20.04로 업그레이드하고 redis 버전 5로 올리고, nginx 버전도 1.19(최신 버전)으로 올리면서 아래의 패키지들을 업데이트했다.(그래도 문제는 계속 발생했다.)

• channels = 3.0.1
• channels_redis = 3.2.0
• django = 3.1.7
• daphne = 3.0.0

복기하기

• 아무리 해도 해결되지 않아서, 일단 가설을 정해서 하나씩 다시 짚어보기로 했다.

1. nginx 문제인가?
2. daphne 서비스 문제인가?
3. redis, channels 문제인가?
4. django 설정 문제인가?

일단 원인 파악을 구체적으로 하기 위해 소켓 통신 튜토리얼(channels 튜토리얼)을 production 서버에서 다시 구현해보면서 어떤 부분이 잘못됐는지 살펴보기로 결정했다.

1. daphne 서버를 8000번 포트로 띄우고, websocket path를 로컬 ip로 설정 해봄.

   wss://127.0.0.1:8000/ws/hole/671

2. wss로 보내기 때문에 daphne는 ssl 설정을 해서 띄웠다. 인증서와 프라이빗 키는 Let's encrypt로 만든 인증서를 활용.

3. daphne 호스트 바인딩으로 public, private ip를 시도해봤지만 가장 명확하게 되는건 로컬호스트(127.0.0.1)라고 결론.

4. 하드코딩된 path로 클라이언트와 소켓 커넥션을 맺으면 명확하게 daphne 서버에서 handshaking 요청을 받아줬다.

→ 즉, daphne 자체는 port, path만 잘 맞으면 동작을 하고 있다는 얘기.

5. channels, channel-redis 버전도 최신 버전이라 버전 이슈는 없는듯 보였고 redis도 아래의 코드로 연결이 잘되는 걸 확인.

$ python3 manage.py shell
>>> import channels.layers
>>> channel_layer = channels.layers.get_channel_layer()
>>> from asgiref.sync import async_to_sync
>>> async_to_sync(channel_layer.send)('test_channel', {'type': 'hello'})
>>> async_to_sync(channel_layer.receive)('test_channel')
{'type': 'hello'}

데모를 통해 위의 4개 가설 중 2,3,4번은 큰 문제가 없을 것 같다는 1차 결론을 내렸다.

다시 테스트 해보기

그 후 튜토리얼에서 했던 설정을 서비스 서버의 설정으로 커스텀해서 테스트해봤다.

• daphne가 응답할 호스트와 포트는 localhost:8000
• websocket 프로토콜은 wss

→ 실패했다. daphne 서버는 응답이 없었고, 여전히 socket은 disconnect 되었다.

다만, nginx access log를 확인해보니 해당 소켓 주소로 HTTP GET 요청은 들어오고 있었는데 WSS 요청은 오지 않았다. 지난번에 올린 글 증상과 비슷해보여서 에러 로그를 좀 더 자세하게 찍어보기로 했다.

참고 :
위에서는 /etc/nginx/sites-enabled/{도메인 이름}에서 설정했는데, 아래부터는 /etc/nginx/conf.d/{도메인 이름}.conf 에 설정을 똑같이 두고 변경했다.

에러 로그 설정 변경 :

error_log /var/log/nginx/live_be/error.log debug;

그리고 websocket path를 아래와 같이 변경했다.

AS-IS : wss://{도메인 이름}:8000/ws/hole/671

TO-BE : wss://{도메인 이름}/ws/hole/671

nginx 설정도 변경해보았다.

upstream your_channel_daphne {
    server 127.0.0.1:8000;
}
server {
	{...}
        listen [::]:443 ssl ipv6only=on; # managed by Certbot
        listen 443 ssl; # managed by Certbot
	{ ...}
        location /ws {
		proxy_pass http://your_channel_daphne;
                proxy_http_version 1.1;
                proxy_set_header    Upgrade $http_upgrade;
                proxy_set_header Connection "upgrade";
                proxy_redirect off;
                proxy_set_header Host $host;
                proxy_set_header X-Real-IP $remote_addr;
                proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
                proxy_set_header X-Forwarded-Host $server_name;
        }
}

설정 이유 : 내가 nginx에서 받던 server_name은 도메인 네임 뿐이었고 포트는 포함하지 않았기 때문에 도메인 이름으로 서버에 요청하면 nginx가 도메인 뒤에 붙은 /ws 를 보고 http://127.0.0.1:8000/ws 로 보낼 것이라고 생각했다.

그 후 다시 소켓 요청을 해보니, 아래와 같은 로그가 찍히기 시작했다.

2021/04/02 16:47:49 [info] 27993#27993: *27 client 143.248.232.194 closed keepalive connection
2021/04/02 16:47:50 [error] 27993#27993: *34 upstream prematurely closed connection while reading response header from upstream, client: 143.248.232.194, server: ask2live.me, request: "GET /ws/hole/671/ HTTP/1.1", upstream: "http://127.0.0.1:8000/ws/hole/671/", host: "www.ask2live.me"

• 문제의 원인을 확실히 nginx 설정으로 좁혔다. nginx 설정 중에서도, gunicorn socket 리버스 프록시는 잘 동작하고 있었기 때문에 daphne 리버스 프록시 쪽으로 방향을 확실하게 좁혔다.
• 구글링을 해보니, Nginx가 해당하는 upstream으로 보내주는데 서버에서 커넥션을 닫는걸 인지해서 발생하는 에러 같아보였다. 즉, 서버에서 차단을 하는 느낌이었다.
• 해결책으로 더 높은 타임아웃 값을 설정해보라고 제시해주었다.
• 그래서 아래와 같이 설정을 변경해보았다.

location /ws {
                proxy_read_timeout 300s;
                proxy_connect_timeout 75s;
	        proxy_pass https://your_channel_daphne;
                proxy_http_version 1.1;
                proxy_set_header    Upgrade $http_upgrade;
                proxy_set_header Connection "upgrade";
                proxy_redirect off;
                proxy_set_header Host $host;
                proxy_set_header X-Real-IP $remote_addr;
                proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
                proxy_set_header X-Forwarded-Host $server_name;
        }

참고 :

• proxy_connect_timeout은 proxy된 서버의 커넥션 타임아웃을 설정하는 컨피그이고, 보통 75초를 넘기지 말라고 한다.
• proxy_read_timeout은 proxy된 서버의 리스폰스 읽기 타임아웃을 설정하는 컨피그이다.

해결

위의 nginx 재설정 이후 다시 소켓 연결을 하니까 2번째 connection 요청에 드디어 연결이 되었다!!!

소켓 연결 1번째 요청은 (소켓 요청이 다른 api response가 성공해야지, connect 될 수 있는데 타이밍 상 그 response가 오지 않는다는 이유로 ) 실패했다.

이 문제 가지고 2~3일을 씨름했는데, 차근차근 트러블 슈팅을 하니까 결국 일단락 되었다.

물론 이 설정이 완벽한게 아니기 때문에 앞으로는 그 타이밍을 최적화 하는 방법을 좀 더 고민해봐야할 것 같다.

결론

혹시나 저와 비슷한 문제로 고민하는 분들이 있다면, 아래의 방법으로 접근해보길 추천드립니다.

• 소켓 통신 서버 포트는 LISTEN이 되어 있는지 확인
• nginx 리버스 프록시가 동작하는지 확인
• 에러 로그를 debug 설정으로 변경해서 로그를 더 자세하게 본다.
• nginx timeout 설정을 건드려본다.

참고 :

• https://stackoverflow.com/questions/36488688/nginx-upstream-prematurely-closed-connection-while-reading-response-header-from
• https://serverfault.com/questions/1041819/nginx-error-47184718-connect-failed-111connection-refused