1

I know there are quite a lot of questions on this and I've read many of them. But still not working and it looks like it should, because there is no visible issue. I have working application on https://mylocalhostdomain.com. There is UI layer and API layer. API is requested via REST or listened via socket.io and on current application everything is working.

But now I am making new UI which is developed on separated server http://localhost:8000. The backend, where socket.io Server is running is Python. So I am running the server:

self._server = socketio.Server(
    async_mode='gevent',
    logger=True,
    engineio_logger=True,
    http_compression=False,
    allow_upgrades=False,
    ping_interval=5,
    cors_allowed_origins=['https://mylocalhostdomain.com', 'http://localhost', 'http://localhost:8000'],
    cors_credentials=True
)

and the client:

this.io = io("https://mylocalhostdomain.com", {
    withCredentials: true
});


this.io.on("connect", () => {
    console.log("Socket connected: ", this.io.connected);
});

Now, when I start new UI on http://localhost:8000, socket.io request is sent (not all request/response data are put below, I've just picked the most important):

Request URL: https://mylocalhostdomain.com/socket.io/?EIO=4&transport=polling&t=OPkWlKv&sid=BqRoMsJFC_dwQVfkAAAI
Status Code: 200 OK

Response Headers:
Access-Control-Allow-Credentials: true
Access-Control-Allow-Headers: Access-Control-Allow-Headers, Origin, Accept, X-Requested-With, Content-Type, Access-Control-Request-Method, Access-Control-Request-Headers, Authorization, csrf_token
Access-Control-Allow-Methods: GET, POST, HEAD, DELETE, OPTIONS, PUT, PATCH
Access-Control-Allow-Origin: http://localhost:8000

Request Headers:
Host: mylocalhostdomain.com
Origin: http://localhost:8000
Referer: http://localhost:8000/
Sec-Fetch-Dest: empty
Sec-Fetch-Mode: cors
Sec-Fetch-Site: cross-site

And the response from the server is:

{"sid":"RLbxQSVaZWQA8WY4AAAP"}

So according to the socket.io doc everything looks correct and no issue here - client sends the request and get the response, but... When I look into the backend (socket.io server) logs, I can't find any information about connecting. Just got the request, send the response, but never got into self._server.on('connect', myhandler). And the same on client - this this.io.on("connect", is never achieved.

But if I copy builded application to the server under the domain mylocalhostdomain.com, everything is working correctly. With the same code. I can see connection message on server logs and in the console there is logged

Socket connected:  true

I really don't understand what issue could be here. Any idea, please?

Edit:

As @MiguelGrinberg asked me about the logs, I am adding them here. The issue is obvious now, but I still have no idea why it is doing. And moreover why it is not doing when the app is on the same domain.

Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:39] "GET /socket.io/?EIO=4&transport=polling&t=OPpPdFz HTTP/1.1" 200 294 0.000717
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:39] "POST /socket.io/?EIO=4&transport=polling&t=OPpPdGV&sid=6mqgrUiYdYAoBkivAAAA HTTP/1.1" 200 195 0.003385
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:39] "GET /socket.io/?EIO=4&transport=polling&t=OPpPdGW&sid=6mqgrUiYdYAoBkivAAAA HTTP/1.1" 200 244 0.001146
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:40] "POST /socket.io/?EIO=4&transport=polling&t=OPpPdLv&sid=6mqgrUiYdYAoBkivAAAA HTTP/1.1" 200 195 0.000438
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:40] "GET /socket.io/?EIO=4&transport=polling&t=OPpPdG-&sid=6mqgrUiYdYAoBkivAAAA HTTP/1.1" 200 208 0.306893
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:50] "GET /socket.io/?EIO=4&transport=polling&t=OPpPfsi HTTP/1.1" 200 294 0.000803
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:50] "POST /socket.io/?EIO=4&transport=polling&t=OPpPftw&sid=vnBK1MSEl-yGaagSAAAC HTTP/1.1" 200 195 0.002087
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:50] "GET /socket.io/?EIO=4&transport=polling&t=OPpPftx&sid=vnBK1MSEl-yGaagSAAAC HTTP/1.1" 200 244 0.000641
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:50] "POST /socket.io/?EIO=4&transport=polling&t=OPpPfuX&sid=vnBK1MSEl-yGaagSAAAC HTTP/1.1" 200 195 0.001395
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: Traceback (most recent call last):
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/gevent/pywsgi.py", line 999, in handle_one_response
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: self.run_application()
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/gevent/pywsgi.py", line 945, in run_application
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: self.result = self.application(self.environ, self.start_response)
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/dozer/leak.py", line 159, in __call__
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: return self.app(environ, start_response)
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/engineio/middleware.py", line 63, in __call__
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: return self.engineio_app.handle_request(environ, start_response)
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/socketio/server.py", line 605, in handle_request
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: return self.eio.handle_request(environ, start_response)
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/engineio/server.py", line 409, in handle_request
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: socket = self._get_socket(sid)
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/engineio/server.py", line 638, in _get_socket
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: raise KeyError('Session is disconnected')
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: KeyError: 'Session is disconnected'
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 2023-02-21T09:55:50Z {'REMOTE_ADDR': '127.0.0.1', 'REMOTE_PORT': '45844', 'HTTP_HOST': 'hub.svale.netledger.com', (hidden keys: 38)} failed with KeyError
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:55:50] "GET /socket.io/?EIO=4&transport=polling&t=OPpPfuW&sid=vnBK1MSEl-yGaagSAAAC HTTP/1.1" 500 161 0.003201
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:56:11] "GET /socket.io/?EIO=4&transport=polling&t=OPpPl2U HTTP/1.1" 200 294 0.000492
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:56:11] "POST /socket.io/?EIO=4&transport=polling&t=OPpPl3a&sid=CNPboXIg1cx_vH0uAAAE HTTP/1.1" 200 195 0.001212
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:56:11] "GET /socket.io/?EIO=4&transport=polling&t=OPpPl3b&sid=CNPboXIg1cx_vH0uAAAE HTTP/1.1" 200 244 0.000269
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:56:11] "POST /socket.io/?EIO=4&transport=polling&t=OPpPl44&sid=CNPboXIg1cx_vH0uAAAE HTTP/1.1" 200 195 0.000427
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 10:56:11] "GET /socket.io/?EIO=4&transport=polling&t=OPpPl43&sid=CNPboXIg1cx_vH0uAAAE HTTP/1.1" 200 208 0.015725
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 11:03:55] "GET /socket.io/?EIO=4&transport=polling&t=OPpRWCU HTTP/1.1" 200 294 0.000469
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 11:03:55] "POST /socket.io/?EIO=4&transport=polling&t=OPpRWDQ&sid=OrVgnPzOKSnRnASrAAAG HTTP/1.1" 200 195 0.002501
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 11:03:55] "GET /socket.io/?EIO=4&transport=polling&t=OPpRWDR&sid=OrVgnPzOKSnRnASrAAAG HTTP/1.1" 200 244 0.000284
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 11:03:55] "POST /socket.io/?EIO=4&transport=polling&t=OPpRWDg&sid=OrVgnPzOKSnRnASrAAAG HTTP/1.1" 200 195 0.000418
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 11:03:55] "GET /socket.io/?EIO=4&transport=polling&t=OPpRWDf&sid=OrVgnPzOKSnRnASrAAAG HTTP/1.1" 200 208 0.001421
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 12:48:24] "GET /socket.io/?EIO=4&transport=polling&t=OPppQmO HTTP/1.1" 200 294 0.001853
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 12:48:24] "POST /socket.io/?EIO=4&transport=polling&t=OPppQr0&sid=RhIDxJa59ziwzjFoAAAI HTTP/1.1" 200 195 0.002786
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 12:48:24] "GET /socket.io/?EIO=4&transport=polling&t=OPppQr1&sid=RhIDxJa59ziwzjFoAAAI HTTP/1.1" 200 244 0.001446
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 12:48:24] "POST /socket.io/?EIO=4&transport=polling&t=OPppQs5&sid=RhIDxJa59ziwzjFoAAAI HTTP/1.1" 200 195 0.000838
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: Traceback (most recent call last):
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/gevent/pywsgi.py", line 999, in handle_one_response
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: self.run_application()
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/gevent/pywsgi.py", line 945, in run_application
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: self.result = self.application(self.environ, self.start_response)
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: File "/opt/opsta/hub-live/py/lib/python3.6/site-packages/dozer/leak.py", line 159, in __call__
Feb 21 12:48:24 fakehub.svale.netledger.com bash[22327]: return self.app(environ, start_response)

but not always an exception shows, most of the time it is only:

Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: KeyError: 'Session is disconnected'
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 2023-02-21T12:31:46Z {'REMOTE_ADDR': '127.0.0.1', 'REMOTE_PORT': '52782', 'HTTP_HOST': 'hub.svale.netledger.com', (hidden keys: 36)} failed with KeyError
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:31:46] "GET /socket.io/?EIO=4&transport=polling&t=OPpzM4A&sid=EgmsiExikKujVkTUAAAS HTTP/1.1" 500 161 0.001793
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:20] "GET /socket.io/?EIO=4&transport=polling&t=OPpzj4h HTTP/1.1" 200 294 0.000523
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:20] "POST /socket.io/?EIO=4&transport=polling&t=OPpzj5W&sid=xHFS_f88Csh2kivxAAAU HTTP/1.1" 200 195 0.002917
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:20] "GET /socket.io/?EIO=4&transport=polling&t=OPpzj5X&sid=xHFS_f88Csh2kivxAAAU HTTP/1.1" 200 244 0.000562
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:20] "POST /socket.io/?EIO=4&transport=polling&t=OPpzj6D&sid=xHFS_f88Csh2kivxAAAU HTTP/1.1" 200 195 0.001073
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:20] "GET /socket.io/?EIO=4&transport=polling&t=OPpzj62&sid=xHFS_f88Csh2kivxAAAU HTTP/1.1" 200 208 0.058138
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:26] "GET /socket.io/?EIO=4&transport=polling&t=OPpzka8 HTTP/1.1" 200 294 0.000540
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:26] "POST /socket.io/?EIO=4&transport=polling&t=OPpzkbL&sid=Oi5iALFU3U3WQfdbAAAW HTTP/1.1" 200 195 0.001478
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:26] "GET /socket.io/?EIO=4&transport=polling&t=OPpzkbM&sid=Oi5iALFU3U3WQfdbAAAW HTTP/1.1" 200 244 0.005079
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:26] "POST /socket.io/?EIO=4&transport=polling&t=OPpzkbb&sid=Oi5iALFU3U3WQfdbAAAW HTTP/1.1" 200 195 0.000340
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:33:26] "GET /socket.io/?EIO=4&transport=polling&t=OPpzkba&sid=Oi5iALFU3U3WQfdbAAAW HTTP/1.1" 200 208 0.001414
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:34:38] "GET /socket.io/?EIO=4&transport=polling&t=OPp-05c HTTP/1.1" 200 294 0.000409
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:34:38] "POST /socket.io/?EIO=4&transport=polling&t=OPp-06S&sid=Wrc_34TOTXUMIiCPAAAY HTTP/1.1" 200 195 0.002795
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:34:38] "GET /socket.io/?EIO=4&transport=polling&t=OPp-06S.0&sid=Wrc_34TOTXUMIiCPAAAY HTTP/1.1" 200 244 0.004195
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:34:38] "POST /socket.io/?EIO=4&transport=polling&t=OPp-073.0&sid=Wrc_34TOTXUMIiCPAAAY HTTP/1.1" 200 195 0.000483
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:34:38] "GET /socket.io/?EIO=4&transport=polling&t=OPp-073&sid=Wrc_34TOTXUMIiCPAAAY HTTP/1.1" 200 208 0.002060
Feb 21 14:39:34 fakehub.svale.netledger.com bash[22327]: 127.0.0.1 - - [2023-02-21 13:34:45] "GET /socket.io/?EIO=4&transport=polling&t=OPp-1rz HTTP/1.1" 200 294 0.000548
Honza
  • 939
  • 2
  • 11
  • 28
  • You said you looked at the server logs. What did you see? Did you enable the Socket.IO detailed logging? – Miguel Grinberg Feb 20 '23 at 15:06
  • You do not have Socket.IO logging enabled in these logs. – Miguel Grinberg Feb 21 '23 at 15:09
  • I am sorry, I don't understand @MiguelGrinberg, could you please give me more details? I've started the server with `logged=True, engineio_logger=True`, this is not enough? – Honza Feb 22 '23 at 08:04
  • Yes, that is how you do it, but the logs you included in your question do not have all the things that are logged when these options are enabled. – Miguel Grinberg Feb 22 '23 at 08:55
  • Oh, but there is nothing more in the logs :-(. What should be here? Maybe it is logged somewhere else. I've looked into `journalctl` and text logs. But we have many logs, so if I know something typical, I could grep it from the logs and maybe I will find something more. Maybe it is logged somewhere else (it shouldn't be, but...). Thank you. – Honza Feb 22 '23 at 09:11
  • You can run any of the server examples in the GitHub repository with logging enabled to see a sample of what's logged. – Miguel Grinberg Feb 22 '23 at 23:56

0 Answers0