Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Event handlers have not been invoked, regardles received event. #1094

Closed
igoras1993 opened this issue Nov 7, 2019 · 6 comments
Closed

Event handlers have not been invoked, regardles received event. #1094

igoras1993 opened this issue Nov 7, 2019 · 6 comments
Labels

Comments

@igoras1993
Copy link
Contributor

It looks like event handlers are not called, not sure why.
I am proxying traffic via Nginx to uWSGI and it works flawlessly. uWSGI is configured in http-websockets mode with gevent .

The events are received (recorded by flask-socketio logger). Here is an example - I've started client app, connected, and send an event "handleSend". Everything was recorded by uWSGI
uWSGI process logs:

Nov 07 12:16:15 vps uwsgi[28171]: Server initialized for gevent_uwsgi.
Nov 07 12:16:15 vps uwsgi[28171]: WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x55d553aedb00 pid: 28171 (default app)
Nov 07 12:16:15 vps uwsgi[28171]: *** uWSGI is running in multiple interpreter mode ***
Nov 07 12:16:15 vps uwsgi[28171]: spawned uWSGI master process (pid: 28171)
Nov 07 12:16:15 vps uwsgi[28171]: spawned uWSGI worker 1 (pid: 28216, cores: 50)
Nov 07 12:16:15 vps uwsgi[28171]: spawned uWSGI worker 2 (pid: 28217, cores: 50)
Nov 07 12:16:15 vps uwsgi[28171]: *** running gevent loop engine [addr:0x55d5519227a0] ***
Nov 07 12:16:55 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Sending packet OPEN data {'sid': 'b3b22eabcba14eeab2c430c32ecaeea7', 'upgrades': [], 'pingTimeout': 60000, 'pingInterval': 25000}
Nov 07 12:16:55 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Sending packet MESSAGE data 0
Nov 07 12:16:55 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Received request to upgrade to websocket
Nov 07 12:16:55 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Upgrade to websocket successful
Nov 07 12:16:55 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Received packet MESSAGE data 0/socket.io,
Nov 07 12:16:55 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Sending packet MESSAGE data 0/socket.io
Nov 07 12:17:04 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Received packet MESSAGE data 2/socket.io,["handleSend","Some message"]
Nov 07 12:17:04 vps uwsgi[28171]: received event "handleSend" from b3b22eabcba14eeab2c430c32ecaeea7 [/socket.io]
Nov 07 12:17:20 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Received packet PING data None
Nov 07 12:17:20 vps uwsgi[28171]: b3b22eabcba14eeab2c430c32ecaeea7: Sending packet PONG data None

BUT look at my handlers:
./app/events/controllers.py:

from ..io import socketio
from flask_socketio import emit

@socketio.on("handleSend")
def handle_click(msg):
    raise ValueError
    with open("/var/xD.out", "a") as f:
        f.write(msg)
    print(msg)

    emit("handleEcho", msg)

@socketio.on('connect')
def test_connect():
    print("CONNECTED")

@socketio.on('disconnect')
def test_disconnect():
    print('Client disconnected')

As You can see, I've even tried writing to a file and rising an exceptions to notice a handler execution, but nothing happend at all (print messages should be recorded in uWSGI logs, as I think).

Here I am instantiating SocketIO:
./app/io.py:

from flask_socketio import SocketIO

socketio = SocketIO(engineio_logger=True, logger=True,
                    cors_allowed_origins="*",
                    cors_credentials=True)

Here is a file passed for uWSGI:
./run_wsgi.py:

import os

os.environ["FLASK_CONFIG_FILENAME"] = "config.prod.yaml"

from app import create_app, socketio

app = create_app()

if __name__ == "__main__":
    socketio.run(app)

I think that socketio is initialized properly in create_app()
./app/init.py:

from flask import Flask, g
from sqlalchemy import create_engine
from sqlalchemy.pool import QueuePool
from sqlalchemy.orm import sessionmaker, scoped_session
from sqlalchemy.exc import InvalidRequestError
import yaml
import os

from .rest.controllers import rest
from .io import socketio


def create_app():
    print("Package name information: ", __name__)
    app = Flask(__name__)

    # configuration file should map to a regular dictionary.
    # inner structures should map to default python objects, like JSON loader
    with open(os.path.join("app", "config", os.environ.get("FLASK_CONFIG_FILENAME", "config.prod.yaml"))) as f:
        config_dictionary = yaml.safe_load(f)
    print("Loaded config yaml: ", config_dictionary)

    app.config.from_mapping(config_dictionary)
    print("Loaded config mapping: ", app.config)

    app.register_blueprint(rest)

    # flask-sqlalchemy setup
    db_engine = create_engine(app.config["DATABASE"]["URL"], poolclass=QueuePool,
                              pool_size=20, max_overflow=0)

    SessionFactory = sessionmaker(bind=db_engine)
    ScopedSession = scoped_session(SessionFactory)

    @app.before_request
    def create_session():
        g.db_session = ScopedSession()

    @app.teardown_appcontext
    def shutdown_session(response_or_exc):

        # weird behaviour: when using app.test_client() and sending request with json=... param,
        # first a appcontext is popped, triggering this function call without actually triggering
        # create_session() before. In case when g attributes are not set, ommit db commiting
        try:
            session = g.db_session
        except AttributeError:
            return

        try:
            session.commit()
        except InvalidRequestError:
            session.rollback()

        ScopedSession.remove()

    # close all pending conections to ensure that references wont be copied into wsgi workers
    db_engine.dispose()

    # connect socket_io app
    socketio.init_app(app)

    return app

As You can see, I am serving rest api also, but this works perfectly fine. Lastly, my uWSGI and NGINX configs:
wsgi.ini

[uwsgi]
module = run_wsgi:app

master = true
processes = 2

http-websockets = true
buffer-size=32768
gevent = 50

socket = /var/tmp/rab-bk.sock
chmod-socket = 664
uid = deploy
gid = deploy
vacuum = true

die-on-term = true

NGINX config:

server {
    if ($host = example.com) {
        return 301 https://$host$request_uri;
    }
    listen *:80;
    server_name example.com;
    return 404;
}

server {
    listen *:443;
    ssl on;
    server_name example.com;

    ssl_certificate /etc/letsencrypt/live/example.com/fullchain.pem;
    ssl_certificate_key /etc/letsencrypt/live/example.com/privkey.pem;
    include /etc/letsencrypt/options-ssl-nginx.conf;
    ssl_dhparam /etc/nginx/ssl/dhparam.pem;

    location /app/ {
		alias /home/deploy/echo/;
		try_files $uri $uri/index.html =404;
	}

    location /socket.io {
        include uwsgi_params;
    	uwsgi_param Upgrade $http_upgrade;
        uwsgi_param Connection "upgrade";
        uwsgi_pass unix:/var/tmp/rab-bk.sock;
    }

    location /rest/ {
        include uwsgi_params;
        uwsgi_pass unix:/var/tmp/rab-bk.sock;
}

Thans for any help in advice!

@igoras1993
Copy link
Contributor Author

Ok, so asked You a little too early. I've just found what I was doing wrong. But still there is one thing that wonders me.

I had two problems in my code.

  1. Due to my misunderstanding, I've put wrong connection url on my client side application.

Look at that line in my NGINX configuration: location /socket.io { ... . I've thought that I should
also point it directly on client side path. So I've added it in connect url:
var socket = io.connect('https://example.com/socket.io').

Solution was to provide just a domain name:
var socket = io.connect('https://example.com/')

Due to such mistake, server was dispatching requests like there was no handler for them, because in fact, they should be handled under additional namespace="/socket.io", which was obviously not used.

  1. Instantiating SocketIO in one module and importing that instance via another which actually register events, causes events to be not handled properly.

This one is weird and I still do not understand the reason.

I've defined socketio instance here:
./app/io.py

from flask_socketio import SocketIO

socketio = SocketIO(engineio_logger=True, logger=True,
                    cors_allowed_origins="*",
                    cors_credentials=True)

And I've imported it to register events here:
./app/events/controllers.py

from ..io import socketio
from flask_socketio import emit

@socketio.on("handleSend")
def handle_click(msg):
    raise ValueError
    with open("/var/xD.out", "a") as f:
        f.write(msg)
    print(msg)

    emit("handleEcho", msg)

@socketio.on('connect')
def test_connect():
    print("CONNECTED")

@socketio.on('disconnect')
def test_disconnect():
    print('Client disconnected')

And finally initialized app there:
./app/init.py

from flask import Flask
from .io import socketio

def create_app():
    app = Flask(__name__)

    # [ Some not important code ]

    # connect socket_io app
    socketio.init_app(app)

    return app

That way, events was not properly registered. I dont know why.
My solution was to move socketio instance declaration to place where events are registered. I've tried other import combinations, but no one woked either.

Now:
./app/events/controllers.py

from ..io import socketio
from flask_socketio import emit

@socketio.on("handleSend")
def handle_click(msg):
    raise ValueError
    with open("/var/xD.out", "a") as f:
        f.write(msg)
    print(msg)

    emit("handleEcho", msg)

@socketio.on('connect')
def test_connect():
    print("CONNECTED")

@socketio.on('disconnect')
def test_disconnect():
    print('Client disconnected')

./app/init.py

from flask import Flask
from .events.controllers import socketio

def create_app():
    app = Flask(__name__)

    # [ Some not important code ]

    # connect socket_io app
    socketio.init_app(app)

    return app

And I've totaly get rid of ./app/io.py.

Now everything works fine, but I wonder if You can provide any explanation on such behaviour?
Have a nice day!

@miguelgrinberg
Copy link
Owner

I believe the problem was that you were not importing the event handlers. Like Flask ones, these handlers are based on decorators, so they need to be imported, even if you never use them directly. The act of importing them triggers the decorator to perform the registration.

@igoras1993
Copy link
Contributor Author

Shame on me...
Thanks a lot Miguel!

@svintit
Copy link

svintit commented Oct 13, 2020

@miguelgrinberg @igoras1993 Apologies for bringing this back up, I have a similar issue and I simply cannot figure out why the handler is not running! I may be misunderstanding something. Any help in understanding what is happening is much, much appreciated!

server

from flask_socketio import SocketIO


socketio = SocketIO(app, cors_allowed_origins="*")


@socketio.on("message")
def socket_get(event, data):
    print("Entered")
    # Do stuff


if __name__ == "__main__":
    socketio.run(app=app, port=6783, debug=True)

client

const
    io = require("socket.io-client"),
    socket = io.connect("my url");

socket.on('connect', function() {
    socket.send('message', {data: 'I\'m connected!'});
});

On the server side, I see the below, but the handler function never runs, no matter what.

server logs

Connected to pydev debugger (build 193.6911.18)
[2020-10-13 20:26:57 +0100] [14574] [INFO] Starting gunicorn 20.0.4
[2020-10-13 20:26:57 +0100] [14574] [INFO] Listening at: http://0.0.0.0:6783 (14574)
[2020-10-13 20:26:57 +0100] [14574] [INFO] Using worker: eventlet
[2020-10-13 20:26:57 +0100] [14576] [INFO] Booting worker with pid: 14576
[2020-10-13 20:26:58.193] [INFO] [engineio.server] [--] Server initialized for eventlet.
[2020-10-13 20:27:01.507] [INFO] [engineio.server] [--] 5b6dcd53ddc4452b95fdf650613bddd0: Sending packet OPEN data {'sid': '5b6dcd53ddc4452b95fdf650613bddd0', 'upgrades': ['websocket'], 'pingTimeout': 60000, 'pingInterval': 25000}
[2020-10-13 20:27:01.507] [INFO] [engineio.server] [--] 5b6dcd53ddc4452b95fdf650613bddd0: Sending packet MESSAGE data 0
[2020-10-13 20:27:01.516] [INFO] [engineio.server] [--] 5b6dcd53ddc4452b95fdf650613bddd0: Received packet MESSAGE data 0/v1,
[2020-10-13 20:27:01.516] [INFO] [engineio.server] [--] 5b6dcd53ddc4452b95fdf650613bddd0: Sending packet MESSAGE data 0/v1
[2020-10-13 20:27:01.519] [INFO] [engineio.server] [--] 5b6dcd53ddc4452b95fdf650613bddd0: Received request to upgrade to websocket
[2020-10-13 20:27:01.531] [INFO] [engineio.server] [--] 5b6dcd53ddc4452b95fdf650613bddd0: Upgrade to websocket successful
[2020-10-13 20:27:01.532] [INFO] [engineio.server] [--] 5b6dcd53ddc4452b95fdf650613bddd0: Received packet MESSAGE data 2/v1,["message",{"data":"I'm connected!"}]
[2020-10-13 20:27:01.532] [INFO] [socketio.server] [--] received event "message" from 5b6dcd53ddc4452b95fdf650613bddd0 [v1]

@miguelgrinberg
Copy link
Owner

@svintit You are using a /v1 namespace that you omitted in your code. The namespace should match for the event handler to be invoked. A handler with the same name that is attached to a different namespace (or to the default namespace as in your case) will not be invoked.

@svintit
Copy link

svintit commented Oct 14, 2020

@miguelgrinberg you are spot on, thanks for that. Didn't realise that if the url passed from the client has any extension after the port it would be used as a namespace!

Much appreciated.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants