Merge ~dirk.zimoch/epics-base:iocLogClientFixes into ~epics-core/epics-base/+git/epics-base:7.0

[Dirk Zimoch]

fix several problems in logClient

Bugfix: don't send errlog to all logClients, only to iocLog
Improvements to minimize message loss when server disconnects:
* detect lost connection to server early
* do not discard buffer at disconnect
* flush buffer directly after reconnect
Other improvements:
* avoid delays on ioc startup and shutdown
* avoid repeated memmove

Relates to bug report https://bugs.launchpad.net/epics-base/+bug/1841608 and Tech-Talk thread https://epics.anl.gov/tech-talk/2019/msg01329.php.

[mdavidsaver (mdavidsaver)]

What necessitates removing shutdown() and adding select()/recv()? To my knowledge send() should return with an error if the socket is, or becomes, disconnected.

review: Needs Information

[Dirk Zimoch (dirk.zimoch)]

Unfortunately send() does not return an error immediately. It simply puts the message into the TCP send queue, even when the peer has already shut down the socket. Only one or more messages later send() returns an error. But by then the messages are lost. The logClient has already "successfully" sent them ti the TCP stack but TCP failed to deliver them and there is no way to recover the messages now.

From the send man page: "No indication of failure to deliver is implicit in a send()."
It only tells you that queuing the message was successful.

When the peer closes the socket, select() will show the socket readable and read() will return 0, but only after everything the peer may have actually send has been read (and discarded).
That is the only reliable way to detect a closed connection.
However this method only works if the receiving side had not been shut down.

I had to google a lot until I found this out. It seems many people get this wrong assuming send() should fail immediately. It doesn't.

I can't find the page that helped me in the end any more, but this one comes close:
https://www.softlab.ntua.gr/facilities/documentation/unix/unix-socket-faq/unix-socket-faq-2.html

[mdavidsaver (mdavidsaver)]

When say "closed connection" do you mean normal closure (FIN/ACK), abnormal closure (RST), and/or (ideally) timeout?

Lack of an application level timeout is a known issue with the logging protocol. Are you trying to address this too?

[Dirk Zimoch (dirk.zimoch)]

I don't know the TCP details. I tested with a local server (ncat) which I terminated and also with our two production servers (syslog-ng adnd logstash) where the firewall closes idle connections after one hour. In both cases I can now detect when the connection breaks. Before I always lost messages.

Which timeout scenario do you have in mind? send() hanging? How could I test that?

[mdavidsaver (mdavidsaver)]

I notice that the page you link states:

> DISCLAIMER: This is my interpretation of the RFCs (I have read all the TCP-related ones I could find), but I have not attempted to examine implementation source code or trace actual connections in order to verify it. I am satisfied that the logic is correct, though.

which makes me smile.

The situation you describe, with a "firewall" in between is actually fairly complicated. And opaque in that the firewall might be acting in different ways depending on how stateful and helpful it is (eg. whether one or both sides get RST).

What I understand about BSD sockets and TCP is that:

1. If the peer maintains the connection, but doesn't call recv() (at all, or not fast enough) then send() will eventually fill the Tx socket buffer FIFO and block until it becomes not full (by peer ACK on recv() ).

2. calling send() on a socket which has been closed (peer calls close()) while the TX FIFO is empty results in an immediate EPIPE.

3. if a send() is in progress because the Tx FIFO is full (or probably when not empty), a peer close results in ECONNRESET.

4. if a the peer has shutdown(SHUT_RD), then send() will succeed until the Tx FIFO is full, then it will block as with #2. When the peer does close(), the send will return with EPIPE. (or probably ECONNRESET if some data was sent, but not ACK'd before the FIN).

5. if the peer simply stops responding, then send() will succeed until the Tx FIFO is full, then block waiting for an ACK which never comes.

So normal, or abnormal, termination of the TCP connection will break a send() immediately after RST or the FIN+ACK handshake completes. peer shutdown(SHUT_RD) or interruption of the network path will not break or error send().

I've just verified 1,2,3,4 on Linux with short python scripts. (I was surprised that #4 doesn't error) #5 I know from past experience.

So I don't think that calling recv() serves the purpose you intend. I think that SO_SNDTIMEO would be a better fit.

That said, the recv() might serve as one piece of a mechanism for a log server to detect condition #5 faster than SO_KEEPALIVE would (imo. SO_KEEPALIVE should also be set). Some extra protocol would be needed to allow a log server to detect this protocol feature.

[Dirk Zimoch (dirk.zimoch)]

4. Was the problem. send does not fail until some time later. But than messages are already lost.
So my fix is not to rely on send failing but on recv returning EOF.
SO_KEEPALIVE has a default timeout of 2 hours and you cannot change it per socket but only system wide. It is totally useless for solving the problems with lost messages. It is there to allow to clean up stale connections and not to run out of file descriptors in server programs that are constantly running. But that's about all. So it may help the log server but not the client.

The problem I solve here is that send succeeds until the FIFO is full, just as you pointed out in 4. and 5.

I cannot confirm 2 though. My tests with ncat as a server have shown that send does not detect immediately when the server has exited (and thus the kernel has closed the socket).

But leaving discussions about how TCP is supposed to work aside, my main argument for this change is: Now it works, before it didn't.

[Andrew Johnson (anj)]

@Dirk: Does your new version still work with the original iocLogServer?

IIRC at connection time that server explicitly closes the socket in the log-server -> client IOC direction because the server never sends data back to the client. I'm not sure whether that might cause the client to get an EOF from a recv() call sooner than with the other log-servers that don't do that close.

[Dirk Zimoch (dirk.zimoch)]

Indeed this looks like a close to the client and it closes the connection, but re-opens it on the next message. No messages are lost. The disconnect is not nice though. I'll have a look how to fix that.

[mdavidsaver (mdavidsaver)]

wrt. iocLogServer, I think it would be reasonable to accept removal of the shutdown(SHUT_WR) in iocLogServer.c. So long as older IOCs can still log against newer iocLogServer (which I think would be true).

[Dirk Zimoch (dirk.zimoch)]

It seems that the broken connection is quite reliably detected at the second send() after the connection had been closed. A dummy send(socket, NULL, 0, 0) seems sufficient to detect the broken connection to iocLogServer as well as to ncat and do Michael's server.py example.

[Andrew Johnson (anj)]

@Dirk: Which architectures have you tested that on?

[Dirk Zimoch (dirk.zimoch)]

Linux so far. I am about to test on vxWorks and Windows right now.

[Dirk Zimoch (dirk.zimoch)]

Hmm... Not all Linux versions behave the same. On some send(socket, NULL, 0, 0) is a NOOP and does not detect a broken connection.

[Dirk Zimoch (dirk.zimoch)]

The send() trick with 0 bytes does not work on all systems. It seems to depend on the Linux kernel version as well.

I am testing now a different solution. On Linux the call ioctl(sock, TIOCOUTQ, &unsent) gives the number of unsent bytes in the TCP output queue. This allows to keep the unsent bytes in the buffer in case it turns out later that the connection is broken.

On macOS there seems to be a similar functionality with getsockopt(sock, SOL_SOCKET, SO_NWRITE, &unsent), but I cannot test because I have no mac.

Other Unix flavors may or may not have such a feature.

For vxWorks I could not find a way to get the number of unsent bytes, neither for version 5.5 nor for 6.7.

I don't know about RTEMS.

On Windows 10 the number of unsent bytes should be available with WSAIoctl(sock, SIO_TCP_INFO, ..._). I spent most of last week to find out why it is not working before finding out that the Win 10 version I got was too old. I am upgrading now. Older Windows versions seem to have no way to find out the number of unsent bytes.

So I can mitigate the problem of message loss for some clients but not for all. Depending on the OS.

[mdavidsaver (mdavidsaver)]

> The send() trick with 0 bytes does not work on all systems.

Unless poll() is used, there is a race condition involved. A second send() will only fail if a RST has been received. This may or may not be platform dependent.

Have you discarded the idea of removing the 'shutdown(SHUT_WR)' from iocLogServer?

[Dirk Zimoch (dirk.zimoch)]

I first want to stay as compatible as possible to existing iocLogServer implementations.

[Dirk Zimoch (dirk.zimoch)]

I made a new branch some commits below the head of this one. How can I change the merge request to the new branch?

[mdavidsaver (mdavidsaver)]

I usually do a force push to replace the existing branch content. I don't think branches can be changed, so the alternative is a new MR.

[Martin Konrad (info-martin-konrad)]

Beware that force pushing messes up the diff on Launchpad's MR. Dirk, have you considered doing this in smaller steps (separate MRs for each issue you are addressing)? This way some of your modifications might get merged faster.

[Ralph Lange (ralph-lange)]

iirc, when you properly supersede the MP through the web interface, you have an option to pull/link the existing conversation to the new proposal.

[Dirk Zimoch (dirk.zimoch)]

So, now I have both variants for discussion.
This one, which requires a change in iocLogServer as well (not to shutdown its write channel).
Or mp+372925 which does not quite work for vxWorks and older Windows and uses an unspecified feature of send() in Linux.

abbd54b... by Dirk Zimoch on 2019-09-19

fix wrong function name in comment

301a6e0... by Dirk Zimoch on 2019-09-19

moved logClientSendMessage and made it static

5f0df84... by Dirk Zimoch on 2019-09-19

increase error message buffer size for long (Windows) error messges

[mdavidsaver (mdavidsaver)]

The other variant was merged, so this one is no longer relevant.

review: Disapprove

Unmerged commits

5f0df84... by Dirk Zimoch on 2019-09-19

increase error message buffer size for long (Windows) error messges

301a6e0... by Dirk Zimoch on 2019-09-19

moved logClientSendMessage and made it static

abbd54b... by Dirk Zimoch on 2019-09-19

fix wrong function name in comment

bad6295... by Dirk Zimoch on 2019-09-18

don't shutdown write channel of iocLogServer to allow logClient to detect disconnect

5801ff2... by Dirk Zimoch on 2019-09-17

use dynamic debug flag for logClient

9dfed16... by Dirk Zimoch on 2019-09-17

improve logClientShow to show unsent bytes on level 2 (and fix level 1)

b925d3f... by Dirk Zimoch on 2019-09-04

(Re-)connect only when there is something to send. This avoids constant useless disconnect/connect cycles if the server (or firewall) keeps closing the connection.

2cafe6d... by Dirk Zimoch on 2019-08-29

detect when server closes connection. can only be done reliably with recv, not with send

diff --git a/modules/database/src/ioc/misc/dbCore.dbd b/modules/database/src/ioc/misc/dbCore.dbd
index 51f9c96..adde24e 100644
--- a/modules/database/src/ioc/misc/dbCore.dbd
+++ b/modules/database/src/ioc/misc/dbCore.dbd
@@ -33,3 +33,6 @@ variable(callbackParallelThreadsDefault,int)
 
 # Real-time operation
 variable(dbThreadRealtimeLock,int)
+
+# show logClient network activity
+variable(logClientDebug,int)
diff --git a/modules/libcom/src/log/iocLog.c b/modules/libcom/src/log/iocLog.c
index e62da20..ba78041 100644
--- a/modules/libcom/src/log/iocLog.c
+++ b/modules/libcom/src/log/iocLog.c
@@ -18,8 +18,10 @@
 
 #define epicsExportSharedSymbols
 #include "envDefs.h"
+#include "errlog.h"
 #include "logClient.h"
 #include "iocLog.h"
+#include "epicsExit.h"
 
 int iocLogDisable = 0;
 
@@ -75,6 +77,24 @@ void epicsShareAPI epicsShareAPI iocLogFlush (void)
 }
 
 /*
+ * logClientSendMessage ()
+ */
+static void logClientSendMessage ( logClientId id, const char * message )
+{
+    if ( !iocLogDisable ) {
+        logClientSend (id, message);
+    }
+}
+
+/*
+ * iocLogClientDestroy()
+ */
+static void iocLogClientDestroy (logClientId id)
+{
+    errlogRemoveListeners (logClientSendMessage, id);
+}
+
+/*
  *  iocLogClientInit()
  */
 static logClientId iocLogClientInit (void)
@@ -89,6 +109,10 @@ static logClientId iocLogClientInit (void)
         return NULL;
     }
     id = logClientCreate (addr, port);
+    if (id != NULL) {
+        errlogAddListener (logClientSendMessage, id);
+        epicsAtExit (iocLogClientDestroy, id);
+    }
     return id;
 }
 
@@ -135,3 +159,4 @@ logClientId epicsShareAPI logClientInit (void)
 {
     return iocLogClientInit ();
 }
+
diff --git a/modules/libcom/src/log/iocLogServer.c b/modules/libcom/src/log/iocLogServer.c
index e707185..4d2f14f 100644
--- a/modules/libcom/src/log/iocLogServer.c
+++ b/modules/libcom/src/log/iocLogServer.c
@@ -486,18 +486,6 @@ static void acceptNewClient ( void *pParam )
 		}
 	}
 
-	status = shutdown(pclient->insock, SHUT_WR);
-	if(status<0){
-        char sockErrBuf[64];
-        epicsSocketConvertErrnoToString ( sockErrBuf, sizeof ( sockErrBuf ) );
-		fprintf (stderr, "%s:%d shutdown err %s\n", __FILE__, __LINE__,
-				sockErrBuf);
-        epicsSocketDestroy ( pclient->insock );
-		free(pclient);
-
-		return;
-	}
-
 	status = fdmgr_add_callback(
 			pserver->pfdctx, 
 			pclient->insock, 
diff --git a/modules/libcom/src/log/logClient.c b/modules/libcom/src/log/logClient.c
index 99ee671..986c7b8 100644
--- a/modules/libcom/src/log/logClient.c
+++ b/modules/libcom/src/log/logClient.c
@@ -21,11 +21,9 @@
 #include <string.h>
 #include <stdio.h>
 
-#define epicsExportSharedSymbols
 #include "dbDefs.h"
 #include "epicsEvent.h"
 #include "iocLog.h"
-#include "errlog.h"
 #include "epicsMutex.h"
 #include "epicsThread.h"
 #include "epicsTime.h"
@@ -33,9 +31,13 @@
 #include "epicsAssert.h"
 #include "epicsExit.h"
 #include "epicsSignal.h"
+#include "epicsExport.h"
 
 #include "logClient.h"
 
+int logClientDebug = 0;
+epicsExportAddress (int, logClientDebug);
+
 typedef struct {
     char                msgBuf[0x4000];
     struct sockaddr_in  addr;
@@ -44,6 +46,7 @@ typedef struct {
     SOCKET              sock;
     epicsThreadId       restartThreadId;
     epicsEventId        stateChangeNotify;
+    epicsEventId        shutdownNotify;
     unsigned            connectCount;
     unsigned            nextMsgIndex;
     unsigned            connected;
@@ -53,7 +56,6 @@ typedef struct {
 } logClient;
 
 static const double      LOG_RESTART_DELAY = 5.0; /* sec */
-static const double      LOG_SERVER_CREATE_CONNECT_SYNC_TIMEOUT = 5.0; /* sec */
 static const double      LOG_SERVER_SHUTDOWN_TIMEOUT = 30.0; /* sec */
 
 /*
@@ -66,10 +68,10 @@ static char* logClientPrefix = NULL;
  */
 static void logClientClose ( logClient *pClient )
 {
-#   ifdef DEBUG
+    if (logClientDebug) {
         fprintf (stderr, "log client: lingering for connection close...");
         fflush (stderr);
-#   endif
+    }
 
     /*
      * mutex on
@@ -84,8 +86,6 @@ static void logClientClose ( logClient *pClient )
         pClient->sock = INVALID_SOCKET;
     }
 
-    pClient->nextMsgIndex = 0u;
-    memset ( pClient->msgBuf, '\0', sizeof ( pClient->msgBuf ) );
     pClient->connected = 0u;
 
     /*
@@ -93,9 +93,8 @@ static void logClientClose ( logClient *pClient )
      */
     epicsMutexUnlock (pClient->mutex);
 
-#   ifdef DEBUG
+    if (logClientDebug)
         fprintf (stderr, "done\n");
-#   endif
 }
 
 /*
@@ -113,6 +112,7 @@ static void logClientDestroy (logClientId id)
     epicsMutexMustLock ( pClient->mutex );
     pClient->shutdown = 1u;
     epicsMutexUnlock ( pClient->mutex );
+    epicsEventSignal ( pClient->shutdownNotify );
 
     /* unblock log client thread blocking in send() or connect() */
     interruptInfo =
@@ -154,18 +154,41 @@ static void logClientDestroy (logClientId id)
         return;
     }
 
-    errlogRemoveListeners ( logClientSendMessage, (void *) pClient );
-
     logClientClose ( pClient );
 
     epicsMutexDestroy ( pClient->mutex );
-   
     epicsEventDestroy ( pClient->stateChangeNotify );
+    epicsEventDestroy ( pClient->shutdownNotify );
 
     free ( pClient );
 }
 
 /*
+ * logClientCheckConnection
+ */
+static void logClientCheckConnection( logClient * pClient )
+{
+    epicsMutexMustLock ( pClient->mutex );
+    while ( pClient->connected ) {
+        struct timeval timeout = { 0, 0 };
+        fd_set set;
+        char buffer[256];
+
+        FD_ZERO ( &set );
+        FD_SET ( pClient->sock, &set );
+        if ( select ( pClient->sock + 1, &set, NULL, NULL, &timeout ) == 0)
+            break;
+        if ( recv ( pClient->sock, buffer, sizeof ( buffer ), 0 ) == 0 ) {
+            fprintf ( stderr, "log client: connection closed by server \"%s\"\n",
+                pClient->name );
+            logClientClose ( pClient );
+            break;
+        }
+    }
+    epicsMutexUnlock ( pClient->mutex );
+}
+
+/*
  * This method requires the pClient->mutex be owned already.
  */
 static void sendMessageChunk(logClient * pClient, const char * message) {
@@ -176,57 +199,24 @@ static void sendMessageChunk(logClient * pClient, const char * message) {
         unsigned msgBufBytesLeft = 
             sizeof ( pClient->msgBuf ) - pClient->nextMsgIndex;
 
-        if ( strSize > msgBufBytesLeft ) {
-            int status;
-
-            if ( ! pClient->connected ) {
-                break;
-            }
-
-            if ( msgBufBytesLeft > 0u ) {
-                memcpy ( & pClient->msgBuf[pClient->nextMsgIndex],
-                    message, msgBufBytesLeft );
-                pClient->nextMsgIndex += msgBufBytesLeft;
-                strSize -= msgBufBytesLeft;
-                message += msgBufBytesLeft;
-            }
-
-            status = send ( pClient->sock, pClient->msgBuf, 
-                pClient->nextMsgIndex, 0 );
-            if ( status > 0 ) {
-                unsigned nSent = (unsigned) status;
-                if ( nSent < pClient->nextMsgIndex ) {
-                    unsigned newNextMsgIndex = pClient->nextMsgIndex - nSent;
-                    memmove ( pClient->msgBuf, & pClient->msgBuf[nSent], 
-                        newNextMsgIndex );
-                    pClient->nextMsgIndex = newNextMsgIndex;
-                }
-                else {
-                    pClient->nextMsgIndex = 0u;
-                }
-            }
-            else {
-                if ( ! pClient->shutdown ) {
-                    char sockErrBuf[64];
-                    if ( status ) {
-                        epicsSocketConvertErrnoToString ( sockErrBuf, sizeof ( sockErrBuf ) );
-                    }
-                    else {
-                        strcpy ( sockErrBuf, "server initiated disconnect" );
-                    }
-                    fprintf ( stderr, "log client: lost contact with log server at \"%s\" because \"%s\"\n", 
-                        pClient->name, sockErrBuf );
-                }
-                logClientClose ( pClient );
-                break;
-            }
+        if ( msgBufBytesLeft < strSize && pClient->nextMsgIndex != 0u && pClient->connected)
+        {
+            /* buffer is full, thus flush it */
+            logClientCheckConnection( pClient );
+            logClientFlush ( pClient );
+            msgBufBytesLeft = sizeof ( pClient->msgBuf ) - pClient->nextMsgIndex;
         }
-        else {
-            memcpy ( & pClient->msgBuf[pClient->nextMsgIndex],
-                message, strSize );
-            pClient->nextMsgIndex += strSize;
+        if ( msgBufBytesLeft == 0u ) {
+            fprintf ( stderr, "log client: messages to \"%s\" are lost\n",
+                pClient->name );
             break;
         }
+        if ( msgBufBytesLeft > strSize) msgBufBytesLeft = strSize;
+        memcpy ( & pClient->msgBuf[pClient->nextMsgIndex],
+            message, msgBufBytesLeft );
+        pClient->nextMsgIndex += msgBufBytesLeft;
+        strSize -= msgBufBytesLeft;
+        message += msgBufBytesLeft;
     }
 }
 
@@ -255,32 +245,25 @@ void epicsShareAPI logClientSend ( logClientId id, const char * message )
 
 void epicsShareAPI logClientFlush ( logClientId id )
 {
+    unsigned nSent = 0u;
+
     logClient * pClient = ( logClient * ) id;
 
-    if ( ! pClient ) {
+    if ( ! pClient || ! pClient->connected ) {
         return;
     }
 
     epicsMutexMustLock ( pClient->mutex );
 
-    while ( pClient->nextMsgIndex && pClient->connected ) {
-        int status = send ( pClient->sock, pClient->msgBuf, 
-            pClient->nextMsgIndex, 0 );
+    while ( nSent < pClient->nextMsgIndex && pClient->connected ) {
+        int status = send ( pClient->sock, pClient->msgBuf + nSent,
+            pClient->nextMsgIndex - nSent, 0 );
         if ( status > 0 ) {
-            unsigned nSent = (unsigned) status;
-            if ( nSent < pClient->nextMsgIndex ) {
-                unsigned newNextMsgIndex = pClient->nextMsgIndex - nSent;
-                memmove ( pClient->msgBuf, & pClient->msgBuf[nSent], 
-                    newNextMsgIndex );
-                pClient->nextMsgIndex = newNextMsgIndex;
-            }
-            else {
-                pClient->nextMsgIndex = 0u;
-            }
+            nSent += (unsigned) status;
         }
         else {
             if ( ! pClient->shutdown ) {
-                char sockErrBuf[64];
+                char sockErrBuf[128];
                 if ( status ) {
                     epicsSocketConvertErrnoToString ( sockErrBuf, sizeof ( sockErrBuf ) );
                 }
@@ -294,6 +277,11 @@ void epicsShareAPI logClientFlush ( logClientId id )
             break;
         }
     }
+    pClient->nextMsgIndex -= nSent;
+    if ( nSent > 0 && pClient->nextMsgIndex > 0 ) {
+        memmove ( pClient->msgBuf, & pClient->msgBuf[nSent],
+            pClient->nextMsgIndex );
+    }
     epicsMutexUnlock ( pClient->mutex );
 }
 
@@ -302,10 +290,10 @@ void epicsShareAPI logClientFlush ( logClientId id )
  */
 static void logClientMakeSock (logClient *pClient)
 {
-    
-#   ifdef DEBUG
+    if (logClientDebug) {
         fprintf (stderr, "log client: creating socket...");
-#   endif
+        fflush (stderr);
+    }
 
     epicsMutexMustLock (pClient->mutex);
    
@@ -314,7 +302,7 @@ static void logClientMakeSock (logClient *pClient)
      */
     pClient->sock = epicsSocketCreate ( AF_INET, SOCK_STREAM, 0 );
     if ( pClient->sock == INVALID_SOCKET ) {
-        char sockErrBuf[64];
+        char sockErrBuf[128];
         epicsSocketConvertErrnoToString ( 
             sockErrBuf, sizeof ( sockErrBuf ) );
         fprintf ( stderr, "log client: no socket error %s\n", 
@@ -323,10 +311,8 @@ static void logClientMakeSock (logClient *pClient)
     
     epicsMutexUnlock (pClient->mutex);
 
-#   ifdef DEBUG
+    if (logClientDebug)
         fprintf (stderr, "done\n");
-#   endif
-
 }
 
 /*
@@ -366,7 +352,7 @@ static void logClientConnect (logClient *pClient)
             }
             else {
                 if ( pClient->connFailStatus != errnoCpy && ! pClient->shutdown ) {
-                    char sockErrBuf[64];
+                    char sockErrBuf[128];
                     epicsSocketConvertErrnoToString (
                         sockErrBuf, sizeof ( sockErrBuf ) );
                     fprintf (stderr,
@@ -392,27 +378,13 @@ static void logClientConnect (logClient *pClient)
     optval = TRUE;
     status = setsockopt (pClient->sock, SOL_SOCKET, SO_KEEPALIVE, (char *)&optval, sizeof(optval));
     if (status<0) {
-        char sockErrBuf[64];
+        char sockErrBuf[128];
         epicsSocketConvertErrnoToString ( 
             sockErrBuf, sizeof ( sockErrBuf ) );
         fprintf (stderr, "log client: unable to enable keepalive option because \"%s\"\n", sockErrBuf);
     }
 
     /*
-     * we don't need full-duplex (clients only write), so we shutdown
-     * the read end of our socket
-     */
-    status = shutdown (pClient->sock, SHUT_RD);
-    if (status < 0) {
-        char sockErrBuf[64];
-        epicsSocketConvertErrnoToString ( 
-            sockErrBuf, sizeof ( sockErrBuf ) );
-        fprintf (stderr, "%s:%d shutdown(%d,SHUT_RD) error was \"%s\"\n", 
-            __FILE__, __LINE__, pClient->sock, sockErrBuf);
-        /* not fatal (although it shouldn't happen) */
-    }
-
-    /*
      * set how long we will wait for the TCP state machine
      * to clean up when we issue a close(). This
      * guarantees that messages are serialized when we
@@ -425,7 +397,7 @@ static void logClientConnect (logClient *pClient)
         lingerval.l_linger = 60*5; 
         status = setsockopt (pClient->sock, SOL_SOCKET, SO_LINGER, (char *) &lingerval, sizeof(lingerval));
         if (status<0) {
-            char sockErrBuf[64];
+            char sockErrBuf[128];
             epicsSocketConvertErrnoToString ( 
                 sockErrBuf, sizeof ( sockErrBuf ) );
             fprintf (stderr, "log client: unable to set linger options because \"%s\"\n", sockErrBuf);
@@ -451,20 +423,21 @@ static void logClientRestart ( logClientId id )
     /* SMP safe state inspection */
     epicsMutexMustLock ( pClient->mutex );
     while ( ! pClient->shutdown ) {
-        unsigned isConn;
+        unsigned isConn, dataToSend;
+
+        logClientCheckConnection( pClient );
 
         isConn = pClient->connected;
+        dataToSend = pClient->nextMsgIndex;
 
         epicsMutexUnlock ( pClient->mutex );
 
-        if ( isConn ) {
+        if ( dataToSend ) {
+            if ( ! isConn ) logClientConnect ( pClient );
             logClientFlush ( pClient );
         }
-        else {
-            logClientConnect ( pClient );
-        }
-        
-        epicsThreadSleep ( LOG_RESTART_DELAY );
+
+        epicsEventWaitWithTimeout ( pClient->shutdownNotify, LOG_RESTART_DELAY);
 
         epicsMutexMustLock ( pClient->mutex );
     }
@@ -480,9 +453,7 @@ static void logClientRestart ( logClientId id )
 logClientId epicsShareAPI logClientCreate (
     struct in_addr server_addr, unsigned short server_port)
 {
-    epicsTimeStamp begin, current;
     logClient *pClient;
-    double diff;
 
     pClient = calloc (1, sizeof (*pClient));
     if (pClient==NULL) {
@@ -507,14 +478,22 @@ logClientId epicsShareAPI logClientCreate (
     pClient->shutdownConfirm = 0;
 
     epicsAtExit (logClientDestroy, (void*) pClient);
-    
+
     pClient->stateChangeNotify = epicsEventCreate (epicsEventEmpty);
     if ( ! pClient->stateChangeNotify ) {
         epicsMutexDestroy ( pClient->mutex );
         free ( pClient );
         return NULL;
     }
-   
+
+    pClient->shutdownNotify = epicsEventCreate (epicsEventEmpty);
+    if ( ! pClient->shutdownNotify ) {
+        epicsMutexDestroy ( pClient->mutex );
+        epicsEventDestroy ( pClient->stateChangeNotify );
+        free ( pClient );
+        return NULL;
+    }
+
     pClient->restartThreadId = epicsThreadCreate (
         "logRestart", epicsThreadPriorityLow, 
         epicsThreadGetStackSize(epicsThreadStackSmall),
@@ -522,35 +501,12 @@ logClientId epicsShareAPI logClientCreate (
     if ( pClient->restartThreadId == NULL ) {
         epicsMutexDestroy ( pClient->mutex );
         epicsEventDestroy ( pClient->stateChangeNotify );
+        epicsEventDestroy ( pClient->shutdownNotify );
         free (pClient);
         fprintf(stderr, "log client: unable to start log client connection watch dog thread\n");
         return NULL;
     }
 
-    /*
-     * attempt to synchronize with circuit connect
-     */
-    epicsTimeGetCurrent ( & begin );
-    epicsMutexMustLock ( pClient->mutex );
-    do {
-        epicsMutexUnlock ( pClient->mutex );
-        epicsEventWaitWithTimeout ( 
-            pClient->stateChangeNotify, 
-            LOG_SERVER_CREATE_CONNECT_SYNC_TIMEOUT / 10.0 ); 
-        epicsTimeGetCurrent ( & current );
-        diff = epicsTimeDiffInSeconds ( & current, & begin );
-        epicsMutexMustLock ( pClient->mutex );
-    }
-    while ( ! pClient->connected && diff < LOG_SERVER_CREATE_CONNECT_SYNC_TIMEOUT );
-    epicsMutexUnlock ( pClient->mutex );
-
-    if ( ! pClient->connected ) {
-        fprintf (stderr, "log client create: timed out synchronizing with circuit connect to \"%s\" after %.1f seconds\n",
-            pClient->name, LOG_SERVER_CREATE_CONNECT_SYNC_TIMEOUT );
-    }
-        
-    errlogAddListener ( logClientSendMessage, (void *) pClient );
-
     return (void *) pClient;
 }
 
@@ -568,24 +524,21 @@ void epicsShareAPI logClientShow (logClientId id, unsigned level)
         printf ("log client: disconnected from log server at \"%s\"\n", pClient->name);
     }
 
-    if (level>1) {
-        printf ("log client: sock=%s, connect cycles = %u\n",
-            pClient->sock==INVALID_SOCKET?"INVALID":"OK",
-            pClient->connectCount);
-    }
-
     if (logClientPrefix) {
         printf ("log client: prefix is \"%s\"\n", logClientPrefix);
     }
-}
 
-/*
- * logClientSendMessage (); deprecated
- */
-void logClientSendMessage ( logClientId id, const char * message )
-{
-    if ( !iocLogDisable ) {
-        logClientSend (id, message);
+    if (level>0) {
+        printf ("log client: sock %s, connect cycles = %u\n",
+            pClient->sock==INVALID_SOCKET?"INVALID":"OK",
+            pClient->connectCount);
+    }
+    if (level>1) {
+        printf ("log client: %u bytes in buffer\n", pClient->nextMsgIndex);
+        if (pClient->nextMsgIndex)
+            printf("-------------------------\n"
+                "%.*s-------------------------\n",
+                (int)(pClient->nextMsgIndex), pClient->msgBuf);
     }
 }
 
diff --git a/modules/libcom/src/log/logClient.h b/modules/libcom/src/log/logClient.h
index 1797bbb..3b3f63a 100644
--- a/modules/libcom/src/log/logClient.h
+++ b/modules/libcom/src/log/logClient.h
@@ -38,7 +38,6 @@ epicsShareFunc void epicsShareAPI iocLogPrefix(const char* prefix);
 /* deprecated interface; retained for backward compatibility */
 /* note: implementations are in iocLog.c, not logClient.c */
 epicsShareFunc logClientId epicsShareAPI logClientInit (void);
-epicsShareFunc void logClientSendMessage (logClientId id, const char *message);
 
 #ifdef __cplusplus
 }