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

Ack Callback and event handler not executed in the same order as received packets #950

Closed
MarcoBrescianini opened this issue Feb 9, 2018 · 6 comments

Comments

@MarcoBrescianini
Copy link

Scenario:

Client connected to a server via WebSocket.
Client is listening for event "bar".
Client emits a message "foo" waiting for ack callback.
Server processes "foo" message sent by client, it sends an ack, then emits a "bar" event.

Expected Behavior:

I expect that "foo" ack callback will be executed before "bar" handler.

Current Behavior:

Event handler is executed before ack callback

Context:

  • Emit method invoked from main queue
  • Ack Callback code is executed synchronously (no dispatch_async in the block provided to OnAckCallback instance)
  • Event Handler code is executed synchronously (no dispatch_async in the block provided to SocketIOClient instance)
  • Handle queue is the default one (main queue)
  • Code is in objective-c
  • Network has a very low latency, so packets are sent and received almost simultaneously

Detailed Description:

I noticed that anytime the SocketManager class receives any kind of packets, it submits a block onto its handleQueue asynchronously, asking a SocketIOClient to handle the parsed packet. If packet is an "event" kind, the client executes event handlers callbacks immediately; If the packet received is an "ack" kind, it delegates the packet handling operation to SocketAckManager, that it will submit a block asynchronously on the queue, provided as argument to "executeAck" method (in this case SocketManager's handleQueue), that will execute the ack's callback.
The chain of events I believe is happening is the following:

  • "foo" ack packet is received.
  • SocketManager dispatches async a block (A) on handle queue. Inside this block, the ack packet will be handled by a client instance
  • "bar" event packet is received.
  • SocketManager dispatches async a block (B) on handle queue. Inside this block, the event packet will be handled by a client instance.
  • At this point, handle queue has two blocks waiting for execution. A - B
  • Block A is executed. SocketAckManager's "executeAck" method is invoked. This will dispatch async a new block (C) on handle queue
  • At this point, handle queue has two blocks waiting for execution. A (executing) - B - C
  • Block B is executed. SocketIOClient handles "bar" event calling any event handler attached to "bar" event.
  • Block C is executed. "foo" ack callback is executed.

Proposed Solution:

Promote SocketAckManager to a class. Change "executeAck" and "timeoutAck" methods to execute ack callback synchronously. The reason why SocketAckManager must be modified to be a class, is that in case of re-entrant invocations in one of the "mutating" methods you get a runtime exception (i.e Simultaneous accesses to [...], but modification requires exclusive access).
I did this editing, and I noticed that the problem doesn't occur anymore.

Side Notes:

I don't have any experience with Swift whatsoever, and I didn't understand entirely Socket.IO library internals either. So, I don't know which side effects these changes could carry.
I'm pretty sure this strange behaviour is not caused by the server implementation, because our Android and Web clients don't seem to show the same behaviour.
You can find below a log where you can see the differences between what happens in the original library implementation and my changed version (sensitive data has been removed):

@nuclearace
Copy link
Member

@MarcoBrescianini Thanks. This was a leftover from when there was more complicated queueing going on. Now that that is cleaned up, this should be straightforward.

Can you checkout the latest development branch?

@MarcoBrescianini
Copy link
Author

Yes I'll try the latest development branch, and i'll let you know

@MarcoBrescianini
Copy link
Author

Hi @nuclearace I've tried the latest commit on the development branch, and It worked. However, I get a runtime error whenever I try to emit another event from the same thread of execution of an ack callback. The execution flow is the following:
SocketAckManager.executeAck -> Do something -> OnAckCallback.timingOutAfter -> Runtime error

This happens if client emits are performed on the main queue, and the SocketManager handle queue is not changed from the default one (main queue). Thread of execution doesn't leave the main queue, and you get a runtime exception because SocketAckManager struct is being mutated while it is already mutating.
However, if you set SocketManager's handle queue to a background queue, this exception doesn't occur obviously.

You can get more insights from the log attached:

Simultaneous accesses to 0x6040000feec8, but modification requires exclusive access.
Previous access (a modification) started at SocketIO`SocketIOClient.handleAck(:data:) + 480 (0x107b95d90).
Current access (a modification) started at:
0 libswiftCore.dylib 0x000000010e49cf00 swift_beginAccess + 505
1 SocketIO 0x0000000107b90580 SocketIOClient.ackHandlers.materializeForSet + 38
2 SocketIO 0x0000000107b693b0 OnAckCallback.timingOut(after:callback:) + 449
3 SocketIO 0x0000000107b69be0 @objc OnAckCallback.timingOut(after:callback:) + 124
4 MyApp 0x00000001086d6ca0 -[app method] + 426
5 MyApp 0x00000001086ef0d0 -[app method] + 578
6 MyApp 0x00000001086d17f0 -[app method] + 341
7 MyApp 0x0000000107aa6290 -[app method] + 722
8 CoreFoundation 0x000000010965f2e0 invoking
+ 140
9 CoreFoundation 0x000000010965f100 -[NSInvocation invoke] + 320
10 MyApp 0x0000000107b4f410 -[app method] + 617
11 MyApp 0x00000001086dca20 -[app method] + 142
12 MyApp 0x00000001086d2c20 -[app method] + 321
13 MyApp 0x00000001086d6830 __38-[app method]block_invoke + 345
14 SocketIO 0x0000000107b69c70 thunk for @callee_unowned @convention(block) (@unowned NSArray) -> () + 61
15 SocketIO 0x0000000107b6a790 partial apply for thunk for @callee_unowned @convention(block) (@unowned NSArray) -> () + 58
16 SocketIO 0x0000000107b6c350 SocketAckManager.executeAck(
:with:) + 387
17 SocketIO 0x0000000107b95bb0 SocketIOClient.handleAck(:data:) + 513
18 SocketIO 0x0000000107b97090 SocketIOClient.handlePacket(
:) + 833
19 SocketIO 0x0000000107bae180 SocketManager.parseEngineMessage(:) + 1507
20 SocketIO 0x0000000107badfb0 closure #1 in SocketManager.parseEngineMessage(:) + 71
21 SocketIO 0x0000000107bae060 partial apply for closure #1 in SocketManager.parseEngineMessage(
:) + 100
22 SocketIO 0x0000000107b69ba0 thunk for @callee_owned () -> () + 41
23 libdispatch.dylib 0x000000010d79916b _dispatch_call_block_and_release + 12
24 libdispatch.dylib 0x000000010d79a1b2 _dispatch_client_callout + 8
25 libdispatch.dylib 0x000000010d7a3eb8 _dispatch_main_queue_callback_4CF + 1260
26 CoreFoundation 0x000000010969de30 CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE + 9
27 CoreFoundation 0x0000000109661b00 __CFRunLoopRun + 2402
28 CoreFoundation 0x00000001096616f0 CFRunLoopRunSpecific + 409
29 GraphicsServices 0x00000001119c7988 GSEventRunModal + 62
30 UIKit 0x000000010a26c537 UIApplicationMain + 159
31 MyApp 0x0000000107aa3610 main + 111
32 libdyld.dylib 0x000000010d80ed80 start + 1

In my humble opinion SocketAckManager should be modified to be a class, to avoid this exception. What do you think about it?

@nuclearace
Copy link
Member

Ah... Yeah I guess that makes sense

@nuclearace
Copy link
Member

@MarcoBrescianini The exclusive access issue should be fixed in development. Sorry it took so long, been busy with actual work stuff.

@MarcoBrescianini
Copy link
Author

Nice! Thanks man, have a good day!

nuclearace added a commit that referenced this issue Mar 11, 2018
* development:
  update changelog
  Remove MARK: for websockets methods
  Use callbacks instead of delegate methods for Starscream
  Fix exclusive access issue
  Execute acks sync. Implement #950
  Fixes build warnings caused by documentation issues.
  update starscream carthage
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants