Logging of TLS ATNA Syslog Sender

[Thomas Papke]

Hi,

 

we have found a properly „minor“ issue that seems to be slightly confusing.

 

We are using ATNA TLS using the org.openhealthtools.ihe.atna.auditor.sender.TLSSyslogSenderImpl sender. This sender “hold” the socket to the ATNA repository and reuse the socket. In case the ATNA repository is restarted, the following log message occure in the client using the TLS sender:

 

***********

2017-02-28T11:26:56,875 ERROR [ihe-atna-sender-0] org.openhealthtools.ihe.atna.auditor.sender.TLSSyslogSenderImpl#send(98) - Caught exception trying to audit to TLS socket, throwing away socket (closed socket?).  Will create a new socket to retry this log message.
java.net.SocketException: Broken pipe (Write failed)
    at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:1.8.0_121]
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111) ~[?:1.8.0_121]
    at java.net.SocketOutputStream.write(SocketOutputStream.java:155) ~[?:1.8.0_121]
    at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:431) ~[?:1.8.0_121]
    at sun.security.ssl.OutputRecord.write(OutputRecord.java:417) ~[?:1.8.0_121]
    at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:876) ~[?:1.8.0_121]
    at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:847) ~[?:1.8.0_121]
    at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:123) ~[?:1.8.0_121]
    at java.io.OutputStream.write(OutputStream.java:75) ~[?:1.8.0_121]
    at org.openhealthtools.ihe.atna.auditor.sender.TLSSyslogSenderImpl.send(TLSSyslogSenderImpl.java:94) ~[ipf-oht-atna-auditor-3.1.1.jar:?]
    at org.openhealthtools.ihe.atna.auditor.sender.TLSSyslogSenderImpl.sendAuditEvent(TLSSyslogSenderImpl.java:140) ~[ipf-oht-atna-auditor-3.1.1.jar:?]
***********

 

From my understanding the implementation in the TLSSyslogSenderImpl already handle this case correctly and retry sending on a new “clean” socket connection. Only LOG.error is misleading here. If you agree, I would recommend to lower the log level here to LOG.debug and just log.error if the second try with the new clean socket also fail.

 

Best regards,

Thomas

InterComponentWare AG:
Vorstand: Matthias Glück
Aufsichtsratsvors.: Prof. Dr. Christof Hettich
Unternehmenssitz: 69190 Walldorf, Altrottstraße 31
AG Mannheim HRB 351761 / USt.-IdNr.: DE 198388516

[Sunil BK]

Hi Thomas

Thanks for reporting this issue. I was about to do the same :)
I do agree that the log level is a bit sensitive here and should be lower to INFO or DEBUG.
Although I would like to do some further testing in order to find the cause of this SocketException.

Kind Regards
Sunil

[Christian Ohr]

Right. 

Log level reduced to DEBUG, kept on ERROR if new socket does not work either.

Christian

Am Mittwoch, 1. März 2017 10:49:49 UTC+1 schrieb Thomas Papke: