using aiocometd to connect the CometD cluster of nginx reverse proxy error about aiocometd HOT 11 CLOSED

Hi @showsmall

If you have multiple servers behind a reverse proxy you have to make sure that all requests from a given client end up on the same upstream server. Otherwise the client won't be able to establish a connection, or after an initial successful connection it would need to re-handshake after every connect request.
http://nginx.org/en/docs/http/load_balancing.html#nginx_load_balancing_with_ip_hash

from aiocometd.

Hi @robertmrk
Nginx uses nginx-sticky-module to ensure that every request goes to the same server at the back end

Each time aiocometd connects to the server, the server will output two logs, and the ClientID of the two logs is the same; if the two logs are distributed on different machines, the ClientID will be different, and then it will return 402.

2019-03-13 23:38:53,158 qtp683287027-13 [ERROR][security] websocket handshake info isStaffHandshake:false,CometdUtil.isCometdEnable():true,canHandshake:true,sessionId:2q7q8ysxfla392hnqa182viad5,staffInfo:null
2019-03-13 23:38:53,843 qtp683287027-16 [ERROR][security. websocket handshake info isStaffHandshake:false,CometdUtil.isCometdEnable():true,canHandshake:true,sessionId:2q7q8ysxfla392hnqa182viad5,staffInfo:null

from aiocometd.

I configured nginx as a reverse proxy with the default load balancing method:

events {
    
}
http {
    upstream cometd-demos {
        server cometd-demos-1:8080;
        server cometd-demos-2:8080;
    }

    server {
        listen 80;

        location / {
            proxy_pass http://cometd-demos/;
        }
    }
}

When I tried to connect I got the same error messages that you did. This is basically what I expected.

Then I configured nginx to use the ip-hash load balancing method:

events {
    
}
http {
    upstream cometd-demos {
        ip_hash;
        server cometd-demos-1:8080;
        server cometd-demos-2:8080;
    }

    server {
        listen 80;

        location / {
            proxy_pass http://cometd-demos/;
        }
    }
}

With this method I was able to connect and use the service without any issues.

Finally I configured the sticky load balancing method. I used the imkulikov/nginx-sticky
image for testing which in theory contains the nginx-sticky-module-ng:

events {
    
}
http {
    upstream cometd-demos {
        sticky;
        server cometd-demos-1:8080;
        server cometd-demos-2:8080;
    }

    server {
        listen 80;

        location / {
            proxy_pass http://cometd-demos/;
        }
    }
}

Using this method I was able to connect as well.

Are you seeing any significant difference in the configuration?
Can you send me the part of your logs where aiocometd tries to connect (make sure you set the logging level to DEBUG on your logger)?

from aiocometd.

@robertmrk
How can the Client method of aiocometd open DEBUG

from aiocometd.

@robertmrk
I use this module.
http://tengine.taobao.org/document/http_upstream_session_sticky.html

from aiocometd.

It is possible that aiocometd is incompatible with http://tengine.taobao.org/document/http_upstream_session_sticky.html

from aiocometd.

You can configure the root logger in your main .py file like this:

import logging

logging.basicConfig(level=logging.DEBUG)

All log messages of your modules will be printed to stdout.
You can either send me the entire log if it doesn't contains sensitive data, or at least the lines created by aiocometd.

I would need to know which transport is chosen after the transport negotiation step.
Since the module you linked implements sticky sessions with cookies, it might be possible that if the websocket transport is chosen by aiocometd then this transport won't get the cookies received by the initially used transport, which might cause a websocket connections to fail.
I would just like to be certain that this is the issue before I make any changes.

from aiocometd.

Hi @robertmrk

/root/PycharmProjects/tomorrow/venv/bin/python /root/PycharmProjects/client/tt.py
DEBUG:asyncio:Using selector: EpollSelector
INFO:aiocometd.client:Opening client with connection types ['websocket', 'long-polling'] ...
INFO:aiocometd.client:Connection types supported by the server: ['websocket', 'long-polling', 'callback-polling']
DEBUG:aiocometd.transports.base:Connect task finished with: {'advice': {'interval': 0, 'reconnect': 'handshake'}, 'channel': '/meta/connect', 'id': '0', 'error': '402::Unknown client', 'successful': False}
Traceback (most recent call last):
File "/root/PycharmProjects/client/tt.py", line 60, in
loop.run_until_complete(chat())
File "/usr/local/python3.6/lib/python3.6/asyncio/base_events.py", line 473, in run_until_complete
return future.result()
File "/root/PycharmProjects/client/tt.py", line 34, in chat
await client.open()
File "/root/PycharmProjects/tomorrow/venv/lib/python3.6/site-packages/aiocometd/client.py", line 264, in open
self._verify_response(response)
File "/root/PycharmProjects/tomorrow/venv/lib/python3.6/site-packages/aiocometd/client.py", line 357, in _verify_response
self._raise_server_error(response)
File "/root/PycharmProjects/tomorrow/venv/lib/python3.6/site-packages/aiocometd/client.py", line 373, in _raise_server_error
raise ServerError(message, response)
aiocometd.exceptions.ServerError: ('Connect request failed.', {'advice': {'interval': 0, 'reconnect': 'handshake'}, 'channel': '/meta/connect', 'id': '0', 'error': '402::Unknown client', 'successful': False})

from aiocometd.

Hi @showsmall

Please try to upgrade to version 0.4.5
The library should now work with reverse proxies where the sticky session feature is implemented using cookies.

from aiocometd.

Hi @robertmrk
Thank you very much for your efforts.
I tested this module for three days.
Discovered the problem: When one of the servers of the nginx back-end proxy shuts down, the "402:: Unknown client" appears when aiocometd initiates the reconnection. I analyze that it may be aiocometd reconnected to the server of the backend of the nginx reverse proxy that survives. The server on this phone does not know the client ID generated by the previous server, which results in the connection retry 402, aiocometd did not regenerate client ID when retrying.

Below is the DEBUG log：

DEBUG:aiocometd.transports.base:Connect task finished with: {'id': '167', 'successful': True, 'channel': '/meta/connect'}
DEBUG:aiocometd.transports.base:Connect task finished with: {'id': '168', 'successful': True, 'channel': '/meta/connect'}
DEBUG:aiocometd.transports.base:Connect task finished with: {'id': '169', 'successful': True, 'channel': '/meta/connect'}
DEBUG:aiocometd.transports.base:Connect task finished with: {'id': '170', 'successful': True, 'channel': '/meta/connect'}
DEBUG:aiocometd.transports.base:Connect task finished with: {'id': '171', 'successful': True, 'channel': '/meta/connect'}
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: {'advice': {'interval': 0, 'reconnect': 'handshake'}, 'channel': '/meta/connect', 'id': '172', 'error': '402::Unknown client', 'successful': False}
DEBUG:aiocometd.transports.base:Connect task finished with: {'ext': {'ack': True}, 'minimumVersion': '1.0', 'clientId': '371ov5d7psqja2rbd0i73axh28s', 'supportedConnectionTypes': ['websocket', 'long-polling', 'callback-polling'], 'channel': '/meta/handshake', 'id': '0', 'version': '1.0', 'successful': True}
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.websocket:Recevie task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
DEBUG:aiocometd.transports.base:Connect task finished with: TransportConnectionClosed('Received CLOSE message on the factory.',)
Traceback (most recent call last):
File "/root/PycharmProjects/client/tt.py", line 98, in
client = loop.run_until_complete(chat(encryptVId,visitorId))
File "/usr/local/python3.6/lib/python3.6/asyncio/base_events.py", line 473, in run_until_complete
return future.result()
File "/root/PycharmProjects/client/tt.py", line 63, in chat
async for message in client:
File "/root/PycharmProjects/tomorrow/venv/lib/python3.6/site-packages/aiocometd/client.py", line 416, in aiter
yield await self.receive()
File "/root/PycharmProjects/tomorrow/venv/lib/python3.6/site-packages/aiocometd/client.py", line 399, in receive
response = await self._get_message(self.connection_timeout)
File "/root/PycharmProjects/tomorrow/venv/lib/python3.6/site-packages/aiocometd/client.py", line 498, in _get_message
raise TransportTimeoutError("Lost connection with the server.")
aiocometd.exceptions.TransportTimeoutError: Lost connection with the server.

from aiocometd.

Hi @showsmall

You were right that if the library was used to connect to services exposed through a reverse proxy with cookie based sticky sessions, then it could fail to connect when it switched to the websocket transport since the cookies were not retained. That issues is now fixed in version 0.4.5.
However, you're now facing a different kind of problem. First you would have to configure health checks in nginx, so it wouldn't route requests to failed upstream servers and/or share the server side session information between the upstream servers. So it wouldn't matter to which server the client would try to connect to.
These are all server side issues and I'm affraid there is nothing else I can do on my side to fix these issues.

from aiocometd.