channelsmultiplexer icon indicating copy to clipboard operation
channelsmultiplexer copied to clipboard

Disconnect dies without exception[BUG]

Open cfytrok opened this issue 5 years ago • 6 comments

Disconnect method stop working without exception. Condions: 1. Many consumers 2. db access in sync_func Bug doesn't reproduce every time. When there are multiple db access calls and db modification calls, it reproduces more often.


import logging
l = logging.getLogger('django.db.backends')
l.setLevel(logging.DEBUG)
l.addHandler(logging.StreamHandler())

class TestConsumer(AsyncJsonWebsocketConsumer):
    async def disconnect(self, close_code):
        l.debug('before sync call')
        await self.sync_func()
        l.debug('after sync call')
        await super().disconnect(close_code)

    @database_sync_to_async
    def sync_func(self):
        l.debug('sync_func start')
        get_user_model().objects.count()
        l.debug('sync_func end')

class DemultiplexerAsyncJson(AsyncJsonWebsocketDemultiplexer):
    applications = {
        "test":TestConsumer,
        "test2": TestConsumer
    }

Logs

(0.001) SELECT "authtoken_token"."key", "authtoken_token"."user_id", "authtoken_token"."created" FROM "authtoken_token" WHERE "authtoken_token"."key" = '276d1578d208f6c4bb7a4cee755cc0f9c8280f3a'; args=('276d1578d208f6c4bb7a4cee755cc0f9c8280f3a',)
(0.001) SELECT "auth_user"."id", "auth_user"."password", "auth_user"."last_login", "auth_user"."is_superuser", "auth_user"."username", "auth_user"."first_name", "auth_user"."last_name", "auth_user"."email", "auth_user"."is_staff", "auth_user"."is_active", "auth_user"."date_joined" FROM "auth_user" WHERE "auth_user"."id" = 1; args=(1,)
WebSocket HANDSHAKING /ws/ [127.0.0.1:53291]
WebSocket CONNECT /ws/ [127.0.0.1:53291]
WebSocket DISCONNECT /ws/ [127.0.0.1:53291]
before sync call
before sync call
sync_func start
sync_func start
(0.001) SELECT COUNT(*) AS "__count" FROM "auth_user"; args=()
sync_func end
after sync call
(0.003) SELECT COUNT(*) AS "__count" FROM "auth_user"; args=()
sync_func end
(0.001) SELECT "authtoken_token"."key", "authtoken_token"."user_id", "authtoken_token"."created" FROM "authtoken_token" WHERE "authtoken_token"."key" = '276d1578d208f6c4bb7a4cee755cc0f9c8280f3a'; args=('276d1578d208f6c4bb7a4cee755cc0f9c8280f3a',)
(0.001) SELECT "auth_user"."id", "auth_user"."password", "auth_user"."last_login", "auth_user"."is_superuser", "auth_user"."username", "auth_user"."first_name", "auth_user"."last_name", "auth_user"."email", "auth_user"."is_staff", "auth_user"."is_active", "auth_user"."date_joined" FROM "auth_user" WHERE "auth_user"."id" = 1; args=(1,)
WebSocket HANDSHAKING /ws/ [127.0.0.1:53295]
WebSocket CONNECT /ws/ [127.0.0.1:53295]

Second 'after sync call' message missed in log.

** Platform (please complete the following information):**

  • OS: Windows 10
  • Django version 2.1.4
  • Django channels version 2.1.5
  • Version 0.0.2

cfytrok avatar Apr 06 '19 15:04 cfytrok

(sorry about the very slow response on this)

the disconnect is waiting here for the db operation. the Demultiplexer will wait for application_close_timeout (default 5 seconds) for all upstream applications to finish.

if you remember how were you closing these connections did you/your client send websocket.close frame or did you have some other method trigger the disconnection?

hishnash avatar Jan 06 '20 00:01 hishnash

I was having a similar issue and just found out this is caused by the demultiplexer __call__ function which sets up the application futures so that it starts cancelling the apps if at least one app is closed. This is in disagreement with the disconnect function which tries to wait for all apps to close. So, when the disconnect upstream is called and the first app closes, the __call__ function kills the remaining apps. So I suggested changing it to ALL_COMPLETED instead of FIRST_COMPLETED

Ken4scholars avatar Apr 26 '20 20:04 Ken4scholars

the issue with ALL_COMPLETED is if one of the upstream consumers raises an exception we will not get it untill all the other ones shut down.

However I will take a look, maybe there is something I can do better in the __call__ function.

hishnash avatar Apr 27 '20 21:04 hishnash

Yes

the issue with ALL_COMPLETED is if one of the upstream consumers raises an exception we will not get it untill all the other ones shut down.

Yes, you are right, that is definitely an issue. But a way around is that if the upstream app really wants the entire connection closed and not just its own stream then it can directly invoke the demultiplexer's websocket_disconnect method since all the apps have a reference to its instance. But of course, that will degrade the architecture by introducing a direct dependency on the demultiplexer which will present some issues if and when a developer decides to make the upstream consumer a stand-alone

Ken4scholars avatar Apr 30 '20 18:04 Ken4scholars

I can investigate FIRST_EXCEPTION this might solve this issue. I will take a look if this works.

I will need to ensure I dont try to route a message to a closed upstream consumer.

hishnash avatar Apr 30 '20 19:04 hishnash

@hishnash, did you manage to fix the bug?

lionavixy avatar Oct 10 '20 07:10 lionavixy