Disconnect dies without exception[BUG]

[cfytrok]

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

[hishnash]

(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?

[Ken4scholars]

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

[hishnash]

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.

[Ken4scholars]

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

[hishnash]

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.

[lionavixy]

@hishnash, did you manage to fix the bug?