jchristn / WatsonWebsocket

A simple C# async websocket server and client for reliable transmission and receipt of data
MIT License
277 stars 53 forks source link

MessageReceived event missing while simultaneously sending in WatsonWsClient #27

Closed Wolverine80 closed 4 years ago

Wolverine80 commented 4 years ago

Hi,

I have a problem and I don't know where to place it not being a developer at all. I am using this websocket to receive and send commands to SoundCraft UI mixer. Works fine up to one problem, that the reply to one (short) sent command won't raise the event and I don't know if it has something do with threading or anything else blocking the moment when the message is coming in. I tested it with making a second client and handle the events there to see if it is really coming in, and it is. The Class handling the Connection is a static class so that the application is using only one single connection throughout its lifetime. Any hint what I am doing wrong?

   public static WatsonWsClient MixConnection { get; set; }
        public static void InitMixer(string URL)
        {
            Uri Uri = new Uri(URL);
            MixConnection = new WatsonWsClient(Uri);
            MixConnection.ServerConnected += EventOnOpen;
            MixConnection.ServerDisconnected += EventOnClose;
            MixConnection.MessageReceived += EventOnMessage;

            //WatsonWsClient TestCon = new WatsonWsClient(Uri);
            //TestCon.MessageReceived += EventOnMessage;
            //TestCon.Start();
        }

        private static void EventOnMessage(object sender, MessageReceivedEventArgs e)
        {
           ......
        }
jchristn commented 4 years ago

Hi @Wolverine80 thanks for your note. Which websocket server are you using? Is it one you've built or something off the shelf?

jchristn commented 4 years ago

By the way, I started digging into this. I haven't found anything yet, but I wanted to let you know I wasn't sitting idle on it. It may take me a while to get to the root of it. Cheers

Wolverine80 commented 4 years ago

Hi, the server is sitting on the Soundcraft mixer device. I am trying to develop a client app for the Elgato StreamDeck to control the mixer. It's a fairly simple design. You just send something like '''SETD^i^2^mute^1''' on the socket and the mixer answers with the changed value. In this example it seems the answer gets swallowed somehow. Or I did not understand websockets and thread design enough. When I change a preset, which results in more messages because several settings changes and takes a little bit longer, I get all needed messages to reflect the changes in my app.

jchristn commented 4 years ago

Thank you @Wolverine80 this is helpful.

Out of curiosity - do ALL responses get swallowed or just some? And if just some, is it seemingly random?

Wolverine80 commented 4 years ago

The short ones with quick responses like in the example never get through. I only see them when I open a second websocket. The commands that change presets take a little longer to respond and I implemented them first, so I did not see the problem until I implemented the controls for single channels.

jchristn commented 4 years ago

Thanks @Wolverine80 I'm working on a test project that will make sure each message received causes an event, even under load. Hopefully this will help expose any issues within the library itself.

Would you be willing to share a bit of your source? Is the server side difficult to set up?

jchristn commented 4 years ago

Hi @Wolverine80 wanted to give you an update. I'm not seeing any issues with a single client and single server with the test project I've built (I should be able to get it committed to github in the next day). I am seeing an issue when multiple clients are connected, but it's only a very small number of messages not getting through. Either A) the event isn't firing, or B) the logic I've implemented to count how many messages were sent/received isn't correct (i.e. use of Interlocked.Add and Interlocked.Increment vs int++ etc. I have some more investigation to do on it.

At any rate I haven't forgotten about this and will keep you posted. Cheers

jchristn commented 4 years ago

Hi @Wolverine80 I resolved my stats/counter issues and I'm having a hard time reproducing what you're experiencing. I'm afraid I'll need to see a bit more of your source to appropriately diagnose. If you have a link to the server-side implementation, I may be able to spend some time trying to reproduce your environment (though my personal situation may make that difficult, I will definitely try).

I did put together a project included in the latest commit called Test.Integrity which specifically spawns a server, some number of clients, and exchanges a fixed number of messages between them. It then counts events, and at the conclusion, displays the stats, which is helpful in diagnosing whether or not events are failing.

In v2.1.7, I had some minor fixes to the library which I don't think will affect stability, but you may want to give it a try.

The Test.Integrity project output is shown below. Everything seems to be ok in the library itself, though it was using the Watson websocket client and server for these tests. All of these tests were 100 messages per client, with a 1KB message size.

1 client:

C:\Code\Watson\WatsonWebsocket-2.1\Test.Integrity\bin\Debug\netcoreapp3.1>Test.Integrity
Starting client 1...
Client waiting for server...
Client connected: ::1:55176
Client detected connection to localhost:8000
All clients connected!
Client detected server ready!
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
Client disconnected from localhost:8000
*** Client disconnected: ::1:55176

Server statistics:
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]

Client statistics
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]

2 clients:

C:\Code\Watson\WatsonWebsocket-2.1\Test.Integrity\bin\Debug\netcoreapp3.1>Test.Integrity
Starting client 1...
Client waiting for server...
Client connected: ::1:55303
Client detected connection to localhost:8000
Starting client 2...
Client waiting for server...
Client connected: ::1:55304
Client detected connection to localhost:8000
All clients connected!
Client detected server ready!
Client detected server ready!
Waiting for 2 clients:
| ::1:55303
| ::1:55304
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
Client disconnected from localhost:8000
*** Client disconnected: ::1:55303
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
*** Client disconnected: ::1:55304
Client disconnected from localhost:8000

Server statistics:
  Sent [200 msgs, 204800 bytes] Received [200 msgs, 204800 bytes]

Client statistics
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]

5 clients:

C:\Code\Watson\WatsonWebsocket-2.1\Test.Integrity\bin\Debug\netcoreapp3.1>Test.Integrity
Starting client 1...
Client waiting for server...
Client connected: ::1:55338
Client detected connection to localhost:8000
Starting client 2...
Client waiting for server...
Client connected: ::1:55339
Client detected connection to localhost:8000
Starting client 3...
Client waiting for server...
Client detected connection to localhost:8000
Client connected: ::1:55340
Starting client 4...
Client waiting for server...
Client connected: ::1:55341
Client detected connection to localhost:8000
Starting client 5...
Client waiting for server...
Client connected: ::1:55342
Client detected connection to localhost:8000
All clients connected!
Client detected server ready!
Client detected server ready!
Client detected server ready!
Client detected server ready!
Client detected server ready!
Waiting for 5 clients:
| ::1:55338
| ::1:55339
| ::1:55340
| ::1:55341
| ::1:55342
Waiting for 5 clients:
| ::1:55338
| ::1:55339
| ::1:55340
| ::1:55341
| ::1:55342
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
Client disconnected from localhost:8000
*** Client disconnected: ::1:55338
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
*** Client disconnected: ::1:55339
Client disconnected from localhost:8000
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
*** Client disconnected: ::1:55340
Client disconnected from localhost:8000
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
Client disconnected from localhost:8000
*** Client disconnected: ::1:55341
Client exiting: Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
*** Client disconnected: ::1:55342
Client disconnected from localhost:8000

Server statistics:
  Sent [500 msgs, 512000 bytes] Received [500 msgs, 512000 bytes]

Client statistics
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]
  Sent [100 msgs, 102400 bytes] Received [100 msgs, 102400 bytes]

Net-net, the library seems to be working as expected.

I'll leave this open a bit longer to give you some time to report back on how you want to proceed. If you're comfortable sharing more of your source so I can try to reproduce with an environment that more closely mimics what you have, please let me know.

Thanks! Joel

Wolverine80 commented 4 years ago

Hi,

the server is a closed source hardware https://www.soundcraft.com/en/products/ui24r So not possible the get to it easily. I uploaded my client here. Code is ugly, but I am not a programmer. https://github.com/Wolverine80/mixertest I wonder if I could it the way I did, open a connection and have the app access it to send messages and also get messages from the server. I don't understand much of the multithreading part, I know the API is using async methods, but I don't know what I have to on my side to make it work correctly.

jchristn commented 4 years ago

Hi @Wolverine80 did you send me the right source? The only code I see here is for WebSocketSharp.

using WebSocketSharp;

namespace UIsocket
{
    public class DataClass
    {
        readonly WebSocket ws = ConnectionClass.MixConnection;

        public DataClass()
        {
            ws.OnError += EventOnError;
            ws.OnClose += EventOnClose;
        }

I'm looking at the UIsocket project. Is there a different project? Cheers, Joel

Wolverine80 commented 4 years ago

You are right. I uploaded an older repository. I updated it to the latest version now.

jchristn commented 4 years ago

Hi @Wolverine80 I don't see anything that would make me think this shouldn't work. You may try changing lines such as ws.SendAsync(msg); to ws.SendAsync(msg).Wait(); because the SendAsync method is async and returns a task. I'm wondering if there are cases where it gets killed before completion.

But it sounds like the issue is receiving messages, not sending them.

I don't think having everything in a static class is a problem, as long as you're sure the websocket client isn't being disposed etc. In general it would be better to not have it in a static class, but then again, most test programs I write are big static classes, so it should be ok.

Could you try refactoring into a non-static class and use .Wait() or use async/await syntax to see if that helps? If you need a hand, I'm happy to do it.

Wolverine80 commented 4 years ago

Hi,

so I wrote a minimal new class. https://github.com/Wolverine80/mixertest It just opens the connection when initiated, keeps the connection alive and the test program send 3 messages. I also used the trace class to capture the return messages to have this on a separate thread, just to be sure. I also used .Wait() and also tried it with an async method for send. The behavior is the same. I won't see any of the 3 return messages with just a single open connection. When I use a second connection it works. It's what commented in in the source code. The output then is

SETD^i.2.mute^1
SETD^i.2.mute^0
SETD^i.2.mute^1

I can't make out what could be wrong with this few lines of code. The HTML5 frontend for the mixer is about 50k lines of javascript and as far as I see also uses a simple websocket. The javascript source is also on GitHub https://github.com/ko7m/SoundcraftUI24R

jchristn commented 4 years ago

Hi @Wolverine80 got it, thanks.

To make sure I understand correctly, when you instantiate MixConnection and assign the three events (ServerConnected, ServerDisconnected, and MessageReceived), you don't get events firing on MessageReceived at all.

But when you instantiate MixConnection with two of the three events (ServerConnected and ServerDisconnected) and then instantiate MixConnectionTest with only MessageReceived, you do get events firing on MixConnectionTest.MessageReceived even though they are being sent out on MixConnection.SendAsync?

Wolverine80 commented 4 years ago

I get events, alone when connecting to the mixer there are about 4500 messages with the whole configuration. But I don't get the immediate event right after sending a message. These events I only see in the MixConnectionTeststream. Yes, both tests are using the same method. Changing profiles or mute groups are coming through though. Maybe because both commands send not just a single reply. The per channel commands are just a SETD^i.2.mute^1 and the mixer replies with the same string when the settings is accepted. When the setting does not change, there is no reply. Makes it really simple to build a responsive front end app even for me.

jchristn commented 4 years ago

Hi @Wolverine80 does your client connect to the HTML5/JS front-end or directly to the mixer? I looked at the JS of the mixer and it's been minified (not a lot of help). Do you have a link to the mixer or any way we can get in touch with them? I wonder if there is any way to enable debugging/verbose logging on their side to get some insight into what they see.

About the only thing I could test here would be to build a server that maintains a queue of some number of messages to send to newly-connected clients and then echos back messages. I could then build counters and MD5 checks in to make sure everything looks good. But that wouldn't tell me that your mixer is behaving correctly (the issue could certainly be in the WatsonWebsocket library though, too!)

Let me know what you think. I'll build the test case out tonight to see if I can reproduce without the mixer.

jchristn commented 4 years ago

Hi @Wolverine80 I just built a new project called Test.Echo (please refer to this commit: https://github.com/jchristn/WatsonWebsocket/commit/adf93895616cca58cd7c6c2a0885c39eedf30e56)

It does the following:

Thus the stats should show that the server sent 5000 initially plus 5000 responses to the 5000 sent by the client, i.e. the server sent 10000 total, and received 5000.

The client should show that it received 5000 initial messages but 5000 echo responses to the 5000 it sent, so the client sent 5000 and received 10000.

I'd love to dig into this further with the mixer vendor if you and they are open to it. It appears, at least with a single client, that the library is working ok.

C:\Code\Watson\WatsonWebsocket-2.1\Test.Echo\bin\Debug\netcoreapp3.1>Test.Echo
[WatsonWsServer.Start] starting on http://localhost:8000/
[Server] started
[Client] started
[WatsonWsServer.AcceptConnections] starting data receiver for ::1:50781
[Server] client connected: ::1:50781
[WatsonWsServer.DataReceiver ::1:50781] starting data receiver
[Client] connected to localhost:8000
[Server] detected client ::1:50781, sending messages
[Client] waiting for server messages
[Server] messages sent
[Server] waiting for client to finish
[Client] waiting for server messages
[Client] server messages received
[Client] sending messages to server
[Client] waiting for server echo messages
[Server] waiting for client to finish
[Client] finished
[WatsonWsClient] dispose requested (websocket state: Open)
[WatsonWsClient] dispose complete
[WatsonWsClient.DataReceiver localhost:8000] canceled
[Client] disconnected from localhost:8000
[WatsonWsServer.DataReceiver ::1:50781] websocket disconnected
[Server] client disconnected: ::1:50781
[WatsonWsServer.DataReceiver ::1:50781] disconnected

Server statistics:
  Sent [10000 msgs, 160000 bytes] Received [5000 msgs, 80000 bytes]

Client statistics
  Sent [5000 msgs, 80000 bytes] Received [10000 msgs, 160000 bytes]

Press ENTER to exit

Please let me know how you'd like to proceed! Cheers, Joel

jchristn commented 4 years ago

Hi @Wolverine80 please re-open if you'd like me to investigate this with those that released the mixer. I don't want to claim this isn't an issue with WatsonWebsocket (maybe it is) but I can't reproduce it. Thanks

Wolverine80 commented 4 years ago

I wrote my own threadsafe websocket class and now it's working as expected.