yet another error - redis and firewalls?

Using Django Async/Channels
1

I had things working, it was very exciting, I was chatting with friends and running send.py to inject messages. then something happened and I can’t figure out what.

This is post 1. I’m loosing track of what is relevant. before I could post this, someone walked me though strace and looking at the redis server logs where I found:

7731:M 17 Feb 2024 15:45:02.894 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.

I will hit post here because maybe what is here is helpful, but I would skip it and read my reply, coming soon…

back to post #1:

it seems to be related to redis as I can make the error go away by using the InMemory backend.

# nginx conf:
  location /ws/ {                                                                                                      
    proxy_pass http://localhost:8085;                                                                                  
    proxy_http_version 1.1;                                                                                            
    proxy_set_header Upgrade $http_upgrade;                                                                            
    proxy_set_header Connection "Upgrade";                                                                             
    proxy_set_header Host $host;                                                                                       
    # unknown "connection_upgrade" variable                                                                            
    # proxy_set_header Connection $connection_upgrade;                                                                 
  }                                                                                                                    

# settings.py
CHANNEL_LAYERS = {                                                                                                     
    "default": {                                                                                                       
        "BACKEND": "channels.layers.InMemoryChannelLayer"                                                              
    }

daphne in a shell so I can see what is going on:

(venv) videoteam@val2:/srv/www/pib$ daphne --port 8085 pib.asgi:application -v 3
2024-02-17 06:29:46,890 INFO     Starting server at tcp:port=8085:interface=127.0.0.1
2024-02-17 06:29:46,890 INFO     HTTP/2 support not enabled (install the http2 and tls Twisted extras)
2024-02-17 06:29:46,890 INFO     Configuring endpoint tcp:port=8085:interface=127.0.0.1
2024-02-17 06:29:46,891 INFO     HTTPFactory starting on 8085
2024-02-17 06:29:46,891 INFO     Starting factory <daphne.http_protocol.HTTPFactory object at 0x7f47d4e9cf50>
2024-02-17 06:29:46,892 INFO     Listening on TCP address 127.0.0.1:8085

this js in a browser:

        const roomName = "pi2"
        console.log('roomName: %s', roomName);
        const chatSocket = new WebSocket(
            'wss://'
            + window.location.host
            + '/ws/pistat/'
            + roomName
            + '/'
        );
        console.log('connected: %s', chatSocket);

console shows:

roomName: pi2
tut.html:26 connected: [object WebSocket]

daphne:

76.227.131.147:48606 - - [17/Feb/2024:06:32:36] "WSCONNECTING /ws/pistat/pi2/" - -
2024-02-17 06:32:36,846 DEBUG    Upgraded connection ['76.227.131.147', 48606] to WebSocket
2024-02-17 06:32:36,855 DEBUG    WebSocket ['76.227.131.147', 48606] open and established
76.227.131.147:48606 - - [17/Feb/2024:06:32:36] "WSCONNECT /ws/pistat/pi2/" - -
2024-02-17 06:32:36,855 DEBUG    WebSocket ['76.227.131.147', 48606] accepted by application

side question that I hope isn’t relevant to this problem but I would like to understand:
why Access denied?

> (venv) videoteam@val2:/srv/www/pib$ node_modules/wscat/bin/wscat --connect wss://ps1.fpgas.mithis.com/ws/pistat/pi2/
error: Unexpected server response: 403

daphne:

76.227.131.147:35638 - - [17/Feb/2024:06:34:40] "WSCONNECTING /ws/pistat/pi2/" - -
2024-02-17 06:34:40,284 DEBUG    Upgraded connection ['76.227.131.147', 35638] to WebSocket
2024-02-17 06:34:40,286 INFO     failing WebSocket opening handshake ('Access denied')
2024-02-17 06:34:40,286 WARNING  dropping connection to peer tcp4:76.227.131.147:35638 with abort=False: Access denied
2024-02-17 06:34:40,286 DEBUG    WebSocket ['76.227.131.147', 35638] rejected by application
76.227.131.147:35638 - - [17/Feb/2024:06:34:40] "WSREJECT /ws/pistat/pi2/" - -
2024-02-17 06:34:40,288 DEBUG    WebSocket closed for ['76.227.131.147', 35638]
76.227.131.147:35638 - - [17/Feb/2024:06:34:40] "WSDISCONNECT /ws/pistat/pi2/" - -

Back to the error I care about. If I use redis:

settings.py
CHANNEL_LAYERS = {                                                                                                     
    "default": {                                                                                                       
        "BACKEND": "channels_redis.core.RedisChannelLayer",                                                            
        "CONFIG": {                                                                                                    
            "hosts": [("127.0.0.1", 6379)],                                                                            
        },                                                                                                             
    },                                                                                                                 
}

reload the js,

tut.html:18 WebSocket connection to 'wss://ps1.fpgas.mithis.com/ws/pistat/pi2/' failed: 
(anonymous)	@	tut.html:18
tut.html:34 Chat socket closed unexpectedly

daphne:

76.227.131.147:42132 - - [17/Feb/2024:06:43:26] "WSCONNECTING /ws/pistat/pi2/" - -
2024-02-17 06:43:26,273 DEBUG    Upgraded connection ['76.227.131.147', 42132] to WebSocket
2024-02-17 06:43:26,365 DEBUG    <asyncio.TransportSocket fd=13, family=2, type=1, proto=6, laddr=('127.0.0.1', 38608), raddr=('127.0.0.1', 6379)> connected to 127.0.0.1:6379: (<_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>, <asyncio.streams.StreamReaderProtocol object at 0x7f8945a90ad0>)
2024-02-17 06:43:26,366 DEBUG    <_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>: Fatal write error on socket transport
Traceback (most recent call last):
  File "/usr/lib/python3.11/asyncio/selector_events.py", line 1057, in write
    n = self._sock.send(data)
        ^^^^^^^^^^^^^^^^^^^^^
BrokenPipeError: [Errno 32] Broken pipe
2024-02-17 06:43:27,017 ERROR    Exception inside application: Error UNKNOWN while writing to socket. Connection lost.
Traceback (most recent call last):
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 442, in send_packed_command
    await self._writer.drain()
  File "/usr/lib/python3.11/asyncio/streams.py", line 378, in drain
    await self._protocol._drain_helper()
  File "/usr/lib/python3.11/asyncio/streams.py", line 167, in _drain_helper
    raise ConnectionResetError('Connection lost')
ConnectionResetError: Connection lost

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/routing.py", line 62, in __call__
    return await application(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/security/websocket.py", line 37, in __call__
    return await self.application(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/sessions.py", line 47, in __call__
    return await self.inner(dict(scope, cookies=cookies), receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/sessions.py", line 263, in __call__
    return await self.inner(wrapper.scope, receive, wrapper.send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/auth.py", line 185, in __call__
    return await super().__call__(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/middleware.py", line 24, in __call__
    return await self.inner(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/routing.py", line 116, in __call__
    return await application(
           ^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/consumer.py", line 94, in app
    return await consumer(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/consumer.py", line 58, in __call__
    await await_many_dispatch(
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/utils.py", line 50, in await_many_dispatch
    await dispatch(result)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/consumer.py", line 73, in dispatch
    await handler(message)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/generic/websocket.py", line 173, in websocket_connect
    await self.connect()
  File "/srv/www/pib/venv/lib/python3.11/site-packages/pistat/consumers.py", line 14, in connect
    await self.channel_layer.group_add(self.group_name, self.channel_name)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels_redis/core.py", line 504, in group_add
    await connection.zadd(group_key, {channel: time.time()})
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/client.py", line 601, in execute_command
    conn = self.connection or await pool.get_connection(command_name, **options)
                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 1040, in get_connection
    await self.ensure_connection(connection)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 1062, in ensure_connection
    await connection.connect()
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 258, in connect
    await self.on_connect()
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 362, in on_connect
    await self.send_command("CLIENT", "SETINFO", "LIB-VER", self.lib_version)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 466, in send_command
    await self.send_packed_command(
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 453, in send_packed_command
    raise ConnectionError(
redis.exceptions.ConnectionError: Error UNKNOWN while writing to socket. Connection lost.
2024-02-17 06:43:27,020 INFO     failing WebSocket opening handshake ('Internal server error')
2024-02-17 06:43:27,020 WARNING  dropping connection to peer tcp4:76.227.131.147:42132 with abort=False: Internal server error
2024-02-17 06:43:27,022 DEBUG    WebSocket closed for ['76.227.131.147', 42132]
76.227.131.147:42132 - - [17/Feb/2024:06:43:27] "WSDISCONNECT /ws/pistat/pi2/" - -

The node wcat gives the same
failing WebSocket opening handshake (‘Access denied’)

2

Post #2:

strace --decode-fds=socket daphne --port 8085 pib.asgi:application -v 3

write(2, "2024-02-17 22:01:09,557 DEBUG "…, 3132024-02-17 22:01:09,557 DEBUG <asyncio.TransportSocket fd=13, family=2, type=1, proto=6, laddr=(‘127.0.0.1’, 39318), raddr=(‘127.0.0.1’, 6379)> connected to 127.0.0.1:6379: (<_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>, <asyncio.streams.StreamReaderProtocol object at 0x7f19d3615190>)) = 313

It looks like the server closed the connection. check the redis logs?

7731:M 17 Feb 2024 15:45:02.894 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.

oh hell, this may b irelivatnt … ignore all this. for now.

3

Side note: Absolutely not. The “InMemory” backend is of extremely limited value under a very few circumstances. See the docs at Channel Layers — Channels 4.0.0 documentation
Personally, I never recommend its use for anything other than testing.

Beyond this, if you are looking for further assistance, please include posting your consumer code.

4

InMemory was just to test the non redis code, not a fix.

my consumer is a tweeked version of the tutorial.

# chat/consumers.py
import json

from channels.generic.websocket import AsyncWebsocketConsumer


class PiStatConsumer(AsyncWebsocketConsumer):

    async def connect(self):
        self.pi_name = self.scope["url_route"]["kwargs"]["pi_name"]
        self.group_name = f"pistat_{self.pi_name}"

        # Join group
        await self.channel_layer.group_add(self.group_name, self.channel_name)
        # print(self.group_name, self.channel_name)

        await self.accept()

    async def disconnect(self, close_code):
        # Leave group
        await self.channel_layer.group_discard(self.group_name, self.channel_name)

    # Receive message from WebSocket
    async def receive(self, text_data):
        text_data_json = json.loads(text_data)
        message = text_data_json["message"]

        # Send message to group
        await self.channel_layer.group_send(
            self.group_name, {"type": "stat.message", "message": message}
        )

    # Receive message from group
    async def stat_message(self, event):
        # pprint(event)
        message = event["message"]

        # Send message to WebSocket
        await self.send(text_data=json.dumps({"message": message}))
6

This should include the location path:
proxy_pass http://localhost:8085/ws/;

I have this as upgrade, not Upgrade. (I have reason to believe that Daphne is expecting this to be lowercase, but nothing specific that I can identify.)

7

made the adjustments, no help.

I’ve tweaked consumers.py a bit to use “stat” instead of “log”, add some pprint()s to get a grip on what is being called when.

 # chat/consumers.py
import json

from pprint import pprint

from channels.generic.websocket import AsyncWebsocketConsumer


class PiStatConsumer(AsyncWebsocketConsumer):

    async def connect(self):
        self.pi_name = self.scope["url_route"]["kwargs"]["pi_name"]
        self.group_name = f"pistat_{self.pi_name}"

        # Join group
        await self.channel_layer.group_add(self.group_name, self.channel_name)
        await self.accept()

    async def disconnect(self, close_code):
        # Leave group
        await self.channel_layer.group_discard(self.group_name, self.channel_name)

    # Receive message from WebSocket
    async def receive(self, text_data):
        text_data_json = json.loads(text_data)
        pprint(text_data_json)
        message = text_data_json["stat.message"]

        # Send message to group
        await self.channel_layer.group_send(
            self.group_name, {"type": "stat.message", "message": message}
        )

    # Receive message from group
    async def stat_message(self, event):
        pprint(event)
        # {'message': 'x', 'type': 'stat.message'}
        message = event["message"]

        # Send message to WebSocket
        await self.send(text_data=json.dumps({"message": message}))

// dcws.js
// Django-Channels Web Socket

function PiStatus(PiID) {

    const logSocket = new WebSocket(
        'wss://'
        + window.location.host
        + '/ws/pistat/'
        + 'pi'+PiID.toString()
        + '/'
    );

    logSocket.onmessage = function(e) {
        const data = JSON.parse(e.data);
        document.querySelector('#log'+PiID.toString()).value += (data.message + '\n');
    };

    logSocket.onclose = function(e) {
        console.error('socket closed unexpectedly');
    };

    document.querySelector('#log-input'+PiID.toString()).focus();
    document.querySelector('#log-input'+PiID.toString()).onkeyup = function(e) {
        if (e.key === 'Enter') {  // enter, return

no firewall:

(venv) videoteam@val2:/srv/www/pib$ daphne --port 8085 pib.asgi:application -v 3
2024-02-18 01:05:56,252 INFO     Starting server at tcp:port=8085:interface=127.0.0.1
2024-02-18 01:05:56,252 INFO     HTTP/2 support not enabled (install the http2 and tls Twisted extras)
2024-02-18 01:05:56,253 INFO     Configuring endpoint tcp:port=8085:interface=127.0.0.1
2024-02-18 01:05:56,253 INFO     HTTPFactory starting on 8085
2024-02-18 01:05:56,254 INFO     Starting factory <daphne.http_protocol.HTTPFactory object at 0x7fdc8d10d110>
2024-02-18 01:05:56,254 INFO     Listening on TCP address 127.0.0.1:8085
127.0.0.1:48544 - - [18/Feb/2024:01:06:02] "WSCONNECTING /ws/pistat/pi2/" - -
2024-02-18 01:06:02,929 DEBUG    Upgraded connection ['127.0.0.1', 48544] to WebSocket
2024-02-18 01:06:03,020 DEBUG    <asyncio.TransportSocket fd=13, family=2, type=1, proto=6, laddr=('127.0.0.1', 40100), raddr=('127.0.0.1', 6379)> connected to 127.0.0.1:6379: (<_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>, <asyncio.streams.StreamReaderProtocol object at 0x7fdc8b19cc90>)
2024-02-18 01:06:03,022 DEBUG    <asyncio.TransportSocket fd=14, family=2, type=1, proto=6, laddr=('127.0.0.1', 40102), raddr=('127.0.0.1', 6379)> connected to 127.0.0.1:6379: (<_SelectorSocketTransport fd=14 read=polling write=<idle, bufsize=0>>, <asyncio.streams.StreamReaderProtocol object at 0x7fdc8b1f2150>)
2024-02-18 01:06:03,029 DEBUG    WebSocket ['127.0.0.1', 48544] open and established
127.0.0.1:48544 - - [18/Feb/2024:01:06:03] "WSCONNECT /ws/pistat/pi2/" - -
2024-02-18 01:06:03,030 DEBUG    WebSocket ['127.0.0.1', 48544] accepted by application
2024-02-18 01:06:18,526 DEBUG    WebSocket incoming frame on ['127.0.0.1', 48544]
2024-02-18 01:06:18,527 INFO     {'stat.message': 'test1'}
2024-02-18 01:06:18,545 INFO     {'message': 'test1', 'type': 'stat.message'}
2024-02-18 01:06:18,545 DEBUG    Sent WebSocket packet to client for ['127.0.0.1', 48544]

sudo systemctl start nftables.service

(venv) videoteam@val2:/srv/www/pib$ daphne --port 8085 pib.asgi:application -v 3
2024-02-18 01:07:39,232 INFO     Starting server at tcp:port=8085:interface=127.0.0.1
2024-02-18 01:07:39,233 INFO     HTTP/2 support not enabled (install the http2 and tls Twisted extras)
2024-02-18 01:07:39,233 INFO     Configuring endpoint tcp:port=8085:interface=127.0.0.1
2024-02-18 01:07:39,233 INFO     HTTPFactory starting on 8085
2024-02-18 01:07:39,234 INFO     Starting factory <daphne.http_protocol.HTTPFactory object at 0x7f3f2b244390>
2024-02-18 01:07:39,234 INFO     Listening on TCP address 127.0.0.1:8085

hit ^r to reload / re-run the js, which will try to connect:

76.227.131.147:54672 - - [18/Feb/2024:01:08:06] "WSCONNECTING /ws/pistat/pi2/" - -
2024-02-18 01:08:06,009 DEBUG    Upgraded connection ['76.227.131.147', 54672] to WebSocket
2024-02-18 01:08:06,101 DEBUG    <asyncio.TransportSocket fd=13, family=2, type=1, proto=6, laddr=('127.0.0.1', 54514), raddr=('127.0.0.1', 6379)> connected to 127.0.0.1:6379: (<_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>, <asyncio.streams.StreamReaderProtocol object at 0x7f3f29e90b10>)
2024-02-18 01:08:06,101 DEBUG    <_SelectorSocketTransport fd=13 read=polling write=<idle, bufsize=0>>: Fatal write error on socket transport
Traceback (most recent call last):
  File "/usr/lib/python3.11/asyncio/selector_events.py", line 1057, in write
    n = self._sock.send(data)
        ^^^^^^^^^^^^^^^^^^^^^
BrokenPipeError: [Errno 32] Broken pipe
2024-02-18 01:08:06,265 ERROR    Exception inside application: Error UNKNOWN while writing to socket. Connection lost.
Traceback (most recent call last):
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 442, in send_packed_command
    await self._writer.drain()
  File "/usr/lib/python3.11/asyncio/streams.py", line 378, in drain
    await self._protocol._drain_helper()
  File "/usr/lib/python3.11/asyncio/streams.py", line 167, in _drain_helper
    raise ConnectionResetError('Connection lost')
ConnectionResetError: Connection lost

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/routing.py", line 62, in __call__
    return await application(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/security/websocket.py", line 37, in __call__
    return await self.application(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/sessions.py", line 47, in __call__
    return await self.inner(dict(scope, cookies=cookies), receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/sessions.py", line 263, in __call__
    return await self.inner(wrapper.scope, receive, wrapper.send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/auth.py", line 185, in __call__
    return await super().__call__(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/middleware.py", line 24, in __call__
    return await self.inner(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/routing.py", line 116, in __call__
    return await application(
           ^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/consumer.py", line 94, in app
    return await consumer(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/consumer.py", line 58, in __call__
    await await_many_dispatch(
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/utils.py", line 50, in await_many_dispatch
    await dispatch(result)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/consumer.py", line 73, in dispatch
    await handler(message)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels/generic/websocket.py", line 173, in websocket_connect
    await self.connect()
  File "/srv/www/pib/venv/lib/python3.11/site-packages/pistat/consumers.py", line 16, in connect
    await self.channel_layer.group_add(self.group_name, self.channel_name)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/channels_redis/core.py", line 504, in group_add
    await connection.zadd(group_key, {channel: time.time()})
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/client.py", line 601, in execute_command
    conn = self.connection or await pool.get_connection(command_name, **options)
                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 1040, in get_connection
    await self.ensure_connection(connection)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 1062, in ensure_connection
    await connection.connect()
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 258, in connect
    await self.on_connect()
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 362, in on_connect
    await self.send_command("CLIENT", "SETINFO", "LIB-VER", self.lib_version)
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 466, in send_command
    await self.send_packed_command(
  File "/srv/www/pib/venv/lib/python3.11/site-packages/redis/asyncio/connection.py", line 453, in send_packed_command
    raise ConnectionError(
redis.exceptions.ConnectionError: Error UNKNOWN while writing to socket. Connection lost.
2024-02-18 01:08:06,268 INFO     failing WebSocket opening handshake ('Internal server error')
2024-02-18 01:08:06,269 WARNING  dropping connection to peer tcp4:76.227.131.147:54672 with abort=False: Internal server error
2024-02-18 01:08:06,270 DEBUG    WebSocket closed for ['76.227.131.147', 54672]
76.227.131.147:54672 - - [18/Feb/2024:01:08:06] "WSDISCONNECT /ws/pistat/pi2/" - -

and no surprise, trying to send messages doesn’t work.

8

So do you have any firewall definitions applying to a loopback address?

If you can tie this to your nftables, then I’m guessing the next step is to review your configuration.

9

Um… now we are into territory I am clueless.

Maybe you can tell me.

(venv) videoteam@val2:/srv/www/pib$ cat /etc/nftables.conf 
#!/usr/sbin/nft -f

flush ruleset

table inet filter {

  chain input {
    type filter hook input priority 0;
    iif "lo" accept;
          tcp dport http counter accept;
          tcp dport https counter accept;
          tcp dport 6379 accept;
          tcp dport ssh counter accept;
              meta l4proto {icmp, icmpv6} counter accept;
              udp dport { 67, 68, 546, 547 } counter accept;
          # tcp dport 8084 counter accept;
        jump internal_networks;
    jump custom_rules;
    ct state invalid,new,untracked counter drop;
  }

  chain internal_networks {
          ip saddr 10.21.0.1/24 counter accept;
      }

  chain custom_rules {
      }

  chain forward {
    type filter hook forward priority 0; policy accept;
        # tcp dport { 1234, 4321 } log prefix "forward " accept;
  }

  chain output {
    type filter hook output priority 0;
  }

}

table ip nat {
        chain postrouting {
                type nat hook postrouting priority 100; policy accept;
                masquerade
        }

        chain prerouting {
                type nat hook prerouting priority -100; policy accept;

                # Netgear PoE switch:
                ip daddr 76.227.131.147 tcp dport { 20080 } dnat to 10.21.0.200:80
                ip daddr 76.227.131.147 tcp dport { 10162 } dnat to 10.21.0.200:10162

# pattern:  x.y.z.o port p: op
# # 10.21.0.171:80 gets 171 80

                ip daddr 76.227.131.147 tcp dport { 10222 } dnat to 10.21.0.102:22
                ip daddr 76.227.131.147 tcp dport { 10244 } dnat to 10.21.0.102:4444

                ip daddr 76.227.131.147 tcp dport { 10322 } dnat to 10.21.0.103:22
                ip daddr 76.227.131.147 tcp dport { 10344 } dnat to 10.21.0.103:4444

                ip daddr 76.227.131.147 tcp dport { 10422 } dnat to 10.21.0.104:22
                ip daddr 76.227.131.147 tcp dport { 10444 } dnat to 10.21.0.104:4444

                ip daddr 76.227.131.147 tcp dport { 10522 } dnat to 10.21.0.105:22
                ip daddr 76.227.131.147 tcp dport { 10544 } dnat to 10.21.0.105:4444

                ip daddr 76.227.131.147 tcp dport { 10722 } dnat to 10.21.0.107:22
                ip daddr 76.227.131.147 tcp dport { 10744 } dnat to 10.21.0.107:4444

                ip daddr 76.227.131.147 tcp dport { 10922 } dnat to 10.21.0.109:22
                ip daddr 76.227.131.147 tcp dport { 10944 } dnat to 10.21.0.109:4444

                ip daddr 76.227.131.147 tcp dport { 11122 } dnat to 10.21.0.111:22
                ip daddr 76.227.131.147 tcp dport { 11144 } dnat to 10.21.0.111:4444

                ip daddr 76.227.131.147 tcp dport { 11322 } dnat to 10.21.0.113:22
                ip daddr 76.227.131.147 tcp dport { 11344 } dnat to 10.21.0.113:4444

                ip daddr 76.227.131.147 tcp dport { 11922 } dnat to 10.21.0.119:22
                ip daddr 76.227.131.147 tcp dport { 11944 } dnat to 10.21.0.119:4444

                ip daddr 76.227.131.147 tcp dport { 12122 } dnat to 10.21.0.121:22
                ip daddr 76.227.131.147 tcp dport { 12144 } dnat to 10.21.0.121:4444

                ip daddr 76.227.131.147 tcp dport { 12322 } dnat to 10.21.0.123:22
                ip daddr 76.227.131.147 tcp dport { 12344 } dnat to 10.21.0.123:4444


                # ip daddr 198.0.220.197 tcp dport { 22622 } dnat to 10.21.0.226:22
        }
}
(venv) videoteam@val2:/srv/www/pib$
10

This is even further outside my expertise - I’ve only used iptables/ufw. So I’m playing catch-up here going through the docs to see if I can understand the structure of these definitions.

This one appears like it should apply, and apply first.

However, what I’m finding in the docs leads to multiple versions of the syntax.

In addition to what you have above, I’m seeing versions in different souces that look like:

  • iffname lo accept
  • iffname "lo" accept
    and
  • iff lo accept

And even if that wasn’t right, I’d also expect that this would have worked:

I’d try replacing the iff filter with each of the iff variants one-by-one to see if the behavior changes.

Another possibility would be to add another rule in the internal_networks section: ip saddr 127.0.0.1/32 accept;

Unfortunately, for me to chase this down further, I’d have to set up an Ubuntu system that has upgraded from iptables to nftables.

11

I used this playbook/template to create nftables.conf

I know the people that make/use it, I’m pretty sure it’s ‘right’

no help.

I’m lightly poking the debconf video team people (I’m one of them) who can likely figure this out in short order, so I wouldn’t encourage you to spend time on this. I’m very interested in knowing what is going on, and I’ll get and post the solution.

12

Well, I know this is no help to you, but as a result of digging into this, I’ve learned a bit about the current state of firewalls in Ubuntu.

(Note: this reflects my current understanding of the situation - I may be mis-interpreting what I’m reading, which means this may not be correct.)

  • nftables in intended to (eventually) replace iptables in Ubuntu. This puts it into the category of “I need to learn more about this.”

  • nftables is already the default in Ubuntu 22.04. The iptables command is symlinked to an executable using the nftables API but supporting the current iptables conf file format.

  • It’s “problematic” to create rules using a mix of the iptables and nftables commands

  • There are currently issues with using Docker in a “pure” nftables environment. I know that docker creates iptables rules to manage container networks. It (docker) relies upon iptables-nft to allow it (docker) to create nftables rules using the iptables syntax.

Anyway, I’m glad I’m learning all this now, I’m sure I’ll need to know it sooner rather than later. Unfortunately, it doesn’t help you…

13

debugging tools
Is there something like this using python or ncc

node_modules/wscat/bin/wscat --connect wss://ps1.fpgas.mithis.com/ws/pistat/pi2/
error: Unexpected server response: 403

and why does this 403?

anyone have the systemd .service/socket files that use command=daphne -u /run/daphne/daphne%(process_num)d.sock --fd 0... like shown here:
https://channels.readthedocs.io/en/stable/deploying.html#nginx-supervisor-ubuntu

I tried to quickly build my own, that didn’t work.

I’m not sure how to proceed, and if I have bumped into a bug in something, I am all for identifying/reporting it. I feel like upgrading daphne to git main, and swapping it for other alternatives? like GitHub - encode/uvicorn: An ASGI web server, for Python. 🦄

given the problem goes away replacing redis with inMemory, I’m guessing it isn’t a problem with daphne. Is there some unit test like code I can run to test the python/redis stuff?

14

Not that I’m aware of.

You also mentioned that this issue goes away when you disable the firewall - I’m inclined to continue believing that that is the source of the issue. (Please confirm whether I understood you correctly on this.)

Actually, I don’t use systemd for my Django / channels stuff. I use supervisord. (Easier to set up for non-root users to manage Django-related processes.)

My command looks like this:
command = /home/mpge/ve/channels/bin/python3 /home/mpge/ve/channels/bin/daphne -u /run/uwsgi/mpge/daphne.sock mpge_channels.asgi:application

I then have nginx set up to proxy through to the unix domain socket (/run/uwsgi/mpge/daphne.sock)

Side note: I use standard (released) versions of Django, Channels, and Redis in about a dozen different deployments with no issues. (It’s a mix of Django 4.2 and 5.0.2, Channels 4, Channels-redis 4.2, and redis 4.5 and 5.0) All running behind nginx. I haven’t experienced anything like what you’ve been describing here.

What you can try is connecting to Daphne directly (it would be with ws and not wss since you don’t have Daphne set up to handle tls, but otherwise the same) I think I saw where you have it set up for port 8005(?) That’ll help determine if the issue is in Daphne or in the nginx / daphne connection.

15

you understand, and this is telling:

this bit of my nftables.conf:

table ip nat {
	chain postrouting {
		type nat hook postrouting priority srcnat; policy accept;
		masquerade
	}

remove masquerade, no error.
yay \o/
Which also explains why this is not seen - most people don’t run production stuff on the router/firewall/nat box.

I know what masquerade is. now to track down why is this a problem and who might care.

16

<conjecture>
Off-the-cuff guess - your /etc/redis.conf file has the line:
bind 127.0.0.1

What might be happening is that nftables is changing the requesting address, such that the address being presented to redis is something other than that.

As a test, you can try commenting that line - and then if it works, find out what the address is that is being used. (Commenting that line allows all addresses to connect to redis - not something you typically want to do.)
</conjecture>

This may be able to be worked around by using a unix domain socket for the Daphne - redis connection. That could avoid all the firewall issues.

17

/etc/redis.conf file has the line:
# bind 127.0.0.1

no error.

I’ll hold off on the workaround until I have tracked down what the problem is.

Any idea of something I can run that should error? something better for a bug report than my web-socket project.

18

You could try using the redis cli, to see if that works.

Or, you may be able to try accessing through channels using the interpreter, like you were doing earlier. Beyond that, I’m not really sure.

19

Any experience with

Do I need docker?
this implies I don’t need it for everything:
" If you need a development environment, run invoke devenv. Note: this relies on docker-compose to build environments, "
and it errors when it needs it:

(venv) videoteam@val2:~/temp/redis-py$ invoke devenv
/bin/bash: line 1: docker-compose: command not found

I’m getting tons of fails with the firewall off.

how do I run just
tests/test_asyncio/test_connection_pool.py

20

Sorry, I have no experience with any of that.