Socket sample: server stop receiving input event

[Juampa]

Good day for all!

As doublemax suggests for this kind of problem, I copy the question published on the forum (original post on: http://forums.wxwidgets.org/viewtopic.php?f=1&t=37369)

I made a heavy test on WriteMsg() -Test2 option on client/server wx/samples- and I got a problem. I would like if someone can detect where the problem comes from.

I've simplified the sample to get this scenery:
+ The client sends only a small string "1;num;ECHO" to the server using WriteMsg().
+ The server read it using ReadMsg().
+ The original reply from server was eliminated to have only "Write --> Read" communication.

The problem is the following: If I execute many Test2 (I use Crtl+F2 shortcut) there is one moment when the server stop receiving messages. If another client connects to the server, the communication will work for this new client.

Some output example now, then I put my modifications so you can test it directly from the socket sample (I'm using wx 2.9.4, on Windows, VS2010).

Client sends Test2:

Welcome to wxSocket demo: Client
Client ready
2:12:36 PM: Trying to connect to localhost:3000
2:12:36 PM: ... socket is now connected.

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:38 PM: WriteMsg sent: 1;0;ECHO
=== Test 2 ends ===
...
=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;268;ECHO
=== Test 2 ends ===

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;269;ECHO
=== Test 2 ends ===

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;270;ECHO
=== Test 2 ends ===

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;271;ECHO
=== Test 2 ends ===

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;272;ECHO
=== Test 2 ends ===

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;273;ECHO
=== Test 2 ends ===

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;274;ECHO
=== Test 2 ends ===

=== Test 2 begins ===
Sending the string with WriteMsg ...done
2:12:52 PM: WriteMsg sent: 1;275;ECHO
=== Test 2 ends ===

Server reads Test2:

OnServerEvent: wxSOCKET_CONNECTION
2:12:36 PM: New client connection from 127.0.0.1:53137 accepted
OnSocketEvent: wxSOCKET_INPUT
2:12:38 PM: === Test 2 begins ===
2:12:38 PM: Got "1;0;ECHO" from client.
...
OnSocketEvent: wxSOCKET_INPUT
2:12:52 PM: === Test 2 begins ===
2:12:52 PM: Got "1;266;ECHO" from client.
2:12:52 PM: === Test 2 ends ===
OnSocketEvent: wxSOCKET_INPUT
2:12:52 PM: === Test 2 begins ===
2:12:52 PM: Got "1;267;ECHO" from client.
2:12:52 PM: === Test 2 ends ===
OnSocketEvent: wxSOCKET_INPUT
2:12:52 PM: === Test 2 begins ===
2:12:52 PM: Got "1;268;ECHO" from client.
2:12:52 PM: === Test 2 ends ===
OnSocketEvent: wxSOCKET_INPUT
2:12:52 PM: === Test 2 begins ===
2:12:52 PM: Got "1;269;ECHO" from client.
2:12:52 PM: === Test 2 ends ===
OnSocketEvent: wxSOCKET_INPUT
2:12:52 PM: === Test 2 begins ===
2:12:52 PM: Got "1;270;ECHO" from client.
2:12:52 PM: === Test 2 ends ===

... cri cri
... cri cri
... No more messages catched


You can see that the server does not receive wxSOCKET_INPUT any more after certain point (270 on this case).
The logic is very simple... How to make more robust this useful Write/Read Msg functions? I need to understand why this happens to solve other more complex applications.

Here my modifications. You can replace the original functions by these ones.

Client.cpp

void MyFrame::OnTest2(wxCommandEvent& WXUNUSED(event))
{
  // Disable socket menu entries (exception: Close Session)
  m_busy = true;
  UpdateStatusBar();

  m_text->AppendText(_("\n=== Test 2 begins ===\n"));

  // Tell the server which test we are running
  unsigned char c = 0xCE;
  m_sock->Write(&c, 1);

  // Here we use ReadMsg and WriteMsg to send messages with
  // a header with size information. Also, the reception is
  // event triggered, so we test input events as well.
  //
  // We need to set no flags here (ReadMsg and WriteMsg are
  // not affected by flags)

  m_sock->SetFlags(wxSOCKET_WAITALL);

  static int counter=0;
  wxString s = wxString::Format("1;%d;ECHO",counter++);
  //wxString s = wxGetTextFromUser(
  //  _("Enter an arbitrary string to send to the server:"),
  //  _("Test 2 ..."),
  //  _("Yes I like wxWidgets!"));

  const wxScopedCharBuffer msg1(s.utf8_str());
  size_t len  = wxStrlen(msg1) + 1;
  wxCharBuffer msg2(wxStrlen(msg1));

  m_text->AppendText(_("Sending the string with WriteMsg ..."));
  m_sock->WriteMsg(msg1, len);
  m_text->AppendText(m_sock->Error() ? _("failed !\n") : _("done\n"));
  wxLogMessage("WriteMsg sent: %s",s);
  //m_text->AppendText(_("Waiting for an event (timeout = 2 sec)\n"));

  //// Wait until data available (will also return if the connection is lost)
  //m_sock->WaitForRead(2);

  //if (m_sock->IsData())
  //{
  //  m_text->AppendText(_("Reading the string back with ReadMsg ..."));
  //  m_sock->ReadMsg(msg2.data(), len);
  //  m_text->AppendText(m_sock->Error() ? _("failed !\n") : _("done\n"));
  //  m_text->AppendText(_("Comparing the two buffers ..."));
  //  if (memcmp(msg1, msg2, len) != 0)
  //  {
  //    m_text->AppendText(_("failed!\n"));
  //    m_text->AppendText(_("Test 2 failed !\n"));
  //  }
  //  else
  //  {
  //    m_text->AppendText(_("done\n"));
  //    m_text->AppendText(_("Test 2 passed !\n"));
  //  }
  //}
  //else
  //  m_text->AppendText(_("Timeout ! Test 2 failed.\n")); 

  m_text->AppendText(_("=== Test 2 ends ===\n"));

  m_busy = false;
  UpdateStatusBar();
}

Server.cpp

void MyFrame::Test2(wxSocketBase *sock)
{
  char buf[4096];

  TestLogger logtest("Test 2");

  // We don't need to set flags because ReadMsg and WriteMsg
  // are not affected by them anyway.

  // Read the message
  wxUint32 len = sock->ReadMsg(buf, sizeof(buf)).LastCount();
  if ( !len )
  {
      wxLogError("Failed to read message.");
      return;
  }

  wxLogMessage("Got \"%s\" from client.", wxString::FromUTF8(buf, len));
  //wxLogMessage("Sending the data back");

  // Write it back
  //sock->WriteMsg(buf, len);
}

Thanks for look this topic.
Best regards

[Vadim Zeitlin]

On Wed, 8 May 2013 06:00:13 -0700 (PDT) Juampa wrote:

J> I made a heavy test on WriteMsg() -Test2 option on client/server
J> wx/samples- and I got a problem. I would like if someone can detect where
J> the problem comes from.

Unfortunately I won't have time to debug this in the foreseeable future.
If you can debug it and find the problem, it would be great, please let us
know if you do. If you can't do it, please provide the absolutely minimal
change to the sample in the form of a patch (please see
http://trac.wxwidgets.org/wiki/HowToSubmitPatches for the instructions
about how to create one) and attach it to a new Trac ticket, hopefully
somebody will be able to look at it at some later time.

Sorry but I simply already have too much to do before 2.9.5 (let alone
3.0) release to be able to help you with this now.

Good luck!
VZ

--
TT-Solutions: wxWidgets consultancy and technical support
http://www.tt-solutions.com/

[Juan Pablo Hernández Vogt]

2013/5/8 Vadim Zeitlin <va...@wxwidgets.org>

On Wed, 8 May 2013 06:00:13 -0700 (PDT) Juampa wrote:

J> I made a heavy test on WriteMsg() -Test2 option on client/server
J> wx/samples- and I got a problem. I would like if someone can detect where
J> the problem comes from.

 Unfortunately I won't have time to debug this in the foreseeable future.
If you can debug it and find the problem, it would be great, please let us
know if you do. If you can't do it, please provide the absolutely minimal
change to the sample in the form of a patch (please see
http://trac.wxwidgets.org/wiki/HowToSubmitPatches for the instructions
about how to create one) and attach it to a new Trac ticket, hopefully
somebody will be able to look at it at some later time.

I'll try to get a solution (the project depends on fix it). I'll put information about this.

Now, to complete my experiences I would like to say something else.

On my project I'm testing this:

1) Win32App--> WriteMsg(msg) --> consoleApp
2) consoleApp send back--> WriteMsg(msg) --> Win32App

Obs: Win32 is the client, console the server.

Here the Win32 application is who first can not receive the "echo" of the message after some time.

After that, If I continue trying sending messages in this fast rain of WriteMsg the attached Debug Alert is raised (write reentrancy?) At this point the server received the message and send the echo back, but wxSOCKET_INPUT are coming while WriteMsg is still working (to get a write reentrancy I gess). That makes me thing on this:

Do I must to SetNotify(false) / SetNotify(true) around the processing code in wxSOCKET_INPUT event?

Or is there another properly way to process socket events?

Going back to client sample, I could not raise that Debug Alert. Instead the server stop first (on "1;771;ECHO") and then client stop on WriteMsg("1;1614;ECHO") for the 10 minutes timeout:

=== Test 2 begins ===
Sending the string with WriteMsg ...done

5:20:09 PM: WriteMsg sent: 1;1614;ECHO

=== Test 2 ends ===

=== Test 2 begins ===

Sending the string with WriteMsg ...

//////// after 10 minutes (timeout) ////////
Sending the string with WriteMsg ...failed !
5:30:09 PM: WriteMsg sent: 1;1615;ECHO

=== Test 2 ends ===

=== Test 2 begins ===

//////// after 10 minutes (timeout) ////////

Sending the string with WriteMsg ...

//////// after 10 minutes (timeout) ////////
Sending the string with WriteMsg ...failed !
5:52:39 PM: WriteMsg sent: 1;1616;ECHO

=== Test 2 ends ===

After all these words the fact is that using only WriteMsg/ReadMsg functions, when a socket stop receiving messages is not recoverable, but the socket can send messages without error (socket->Error()==wxSOCKET_NOERROR) and a wxSOCKET_LOST event is correctly detected when the the peer is closed.

Regards,

JP

[Vadim Zeitlin]

On Wed, 8 May 2013 18:37:27 +0200 Juan Pablo Hernández Vogt wrote:

JPHV> I'll try to get a solution (the project depends on fix it). I'll put
JPHV> information about this.

Thanks in advance and good luck!

JPHV> After that, If I continue trying sending messages in this fast rain of
JPHV> WriteMsg the attached *Debug Alert* is raised (*write reentrancy?*)

This is clearly a bug and a good starting point for the investigation. If
you can understand why/when exactly does this happen, i.e. why doesn't it
happen every time but does happen eventually, it could already shed some
light on what goes on.

JPHV> Do I must to SetNotify(false) / SetNotify(true) around the processing code
JPHV> in wxSOCKET_INPUT event?

Do you mean inside wxSocket code or in your handler? It shouldn't be
necessary in your handler, as far as I know... But maybe wxSocket should do
something to ensure that such reentrancies can't happen, even if the
handler reuses the same socket again. Or at least asserts if it's really
forbidden to do this.

Regards,

[JimJW]

Hello,
I too have run into this problem and I hope some of the following might be
helpful.

My client server application posts null terminated UTF8 string messages back
and forth. It would work for a while, then just lock up.

I have modified the sample code client/server example to show the problem
sockets.zip <http://wxwidgets.10942.n7.nabble.com/file/n86640/sockets.zip>
- my hack has added a "test 4" where the client responds to each reply from
the server by sending a new message. This would be expected to run
indefinitely, but stops after a few rounds.
Server shows:
...
20:57:19: === Test 4 begins ===
20:57:19: Got the data " Test 4 pass No. 16". Sending it back
20:57:19: === Test 4 ends ===
OnSocketEvent: wxSOCKET_INPUT
20:57:19: === Test 4 begins ===
20:57:19: Got the data " Test 4 pass No. 17". Sending it back
20:57:19: === Test 4 ends ===
OnSocketEvent: wxSOCKET_INPUT
20:57:19: === Test 4 begins ===
20:57:19: Got the data " Test 4 pass No. 18". Sending it back
20:57:19: === Test 4 ends ===

Client shows:
...
=== Test 4 pass done. ===
Sending "Test 4 pass No. 16" to the server ...done
20:57:19: Input available on the socket
Socket input event.Receiving the buffer back from server ...done
Test 4 pass No. 16
=== Test 4 pass done. ===
Sending "Test 4 pass No. 17" to the server ...done
20:57:19: Input available on the socket
Socket input event.Receiving the buffer back from server ...done
Test 4 pass No. 17
=== Test 4 pass done. ===
Sending "Test 4 pass No. 18" to the server ...done
20:57:19: Input available on the socket
Socket input event.Receiving the buffer back from server ...done
Test 4 pass No. 18
=== Test 4 pass done. ===
Sending "Test 4 pass No. 19" to the server ...done

As can be seen, the client believes it has sent pass number 19, but there is
no input event at the server.

My first guess was that there was a problem with repeatedly disabling and
enabling input events - perhaps a timing problem where the data arrives
while the input event is being enabled, and fails to trigger the event.

I modified my original application to keep events permanently enabled. It
now reads all data available into a fifo, and pulls out complete messages
when available. I have not yet seen this fail.

I assumed I could fix my hacked sample code in the same way. I tried
removing the
sock->SetNotify(wxSOCKET_LOST_FLAG);
lines. Although this works for longer, it still fails fairly quickly.

I must admit that I don't understand how this should work I see that
sock->SetNotify() simply changes a member variable, so I don't see how
another input event would be generated if a message had been received
between the read and re-enabling input events.

I hope this contains some useful clue for someone that does understand

This was done with wxWidgets 3 on Windows 7, built with Mingw.

Regards
Jim



--
View this message in context: http://wxwidgets.10942.n7.nabble.com/Socket-sample-server-stop-receiving-input-event-tp84310p86640.html
Sent from the wxWidgets - Users mailing list archive at Nabble.com.

[Vadim Zeitlin]

On Fri, 14 Feb 2014 10:22:41 -0800 (PST) JimJW wrote:

J> I have modified the sample code client/server example to show the problem
J> sockets.zip <http://wxwidgets.10942.n7.nabble.com/file/n86640/sockets.zip>

Sorry, I don't have the time to debug this right now anyhow, but if I do
have time later it would be much more helpful to have a patch to the socket
sample instead of the ZIP archive. Could you please make one as described
in http://trac.wxwidgets.org/wiki/HowToSubmitPatches?

TIA!

[JimJW]

Thanks for the gentle advice on how things should be done here.
Here is my patch mypatch.patch
<http://wxwidgets.10942.n7.nabble.com/file/n86697/mypatch.patch> .
This was done on a clean checkout from trunk and just contains changes to
the two client/server sample source files.
This time, I built everything with MS Visual Studio Express 2013, and got
the same result (lost receive events).

Best Regards
Jim



--
View this message in context: http://wxwidgets.10942.n7.nabble.com/Socket-sample-server-stop-receiving-input-event-tp84310p86697.html