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

SocketTimeoutException: Read timed out exception stacktrace every second with ssl debug set to true #1064

Open
brianreinhold opened this issue Nov 3, 2024 · 0 comments

Comments

@brianreinhold
Copy link

I get the following stacktrace

-->javax.net.ssl|WARNING|E1|MQTT Rec: @{"organization":"A&D", "program":"Cardiac Recovery"}|2024-11-02 19:12:05.463 EDT|SSLSocketImpl.java:1666|handling exception (
"throwable" : {
  java.net.SocketTimeoutException: Read timed out
  	at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:283)
  	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:309)
  	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350)
  	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803)
  	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
  	at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:478)
  	at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:472)
  	at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:70)
  	at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1455)
  	at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1059)
  	at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:966)
  	at java.base/java.io.DataInputStream.readByte(DataInputStream.java:271)
  	at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92)
  	at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137)
  	at java.base/java.lang.Thread.run(Thread.java:833)}

every second when running with tls (ssl) debug turned on System.setProperty("javax.net.debug", "SSL");

Looking at the source code here at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) I see this:

		try {
			// read header
			if (remLen < 0) {
				// Assume we can read the whole header at once.
				// The header is very small so it's likely we
				// are able to read it fully or not at all.
				// This keeps the parser lean since we don't
				// need to cope with a partial header.
				// Should we lose synch with the stream,
				// the keepalive mechanism would kick in
				// closing the connection.
				bais.reset();
				
				byte first = in.readByte();
				clientState.notifyReceivedBytes(1);

				byte type = (byte) ((first >>> 4) & 0x0F);
				if ((type < MqttWireMessage.MESSAGE_TYPE_CONNECT) ||
						(type > MqttWireMessage.MESSAGE_TYPE_DISCONNECT)) {
					// Invalid MQTT message type...
					throw ExceptionHelper.createMqttException(MqttException.REASON_CODE_INVALID_MESSAGE);
				}
				remLen = MqttWireMessage.readMBI(in).getValue();
				bais.write(first);
				// bit silly, we decode it then encode it
				bais.write(MqttWireMessage.encodeMBI(remLen));
				packet = new byte[(int)(bais.size()+remLen)];
				packetLen = 0;
			}
			
			// read remaining packet
			if (remLen >= 0) {
				// the remaining packet can be read with timeouts
				readFully();

				// reset packet parsing state 
				remLen = -1;
				
				byte[] header = bais.toByteArray();
				System.arraycopy(header,0,packet,0, header.length);
				message = MqttWireMessage.createWireMessage(packet);
				// @TRACE 301= received {0} 
				log.fine(CLASS_NAME, methodName, "301",new Object[] {message});
			}
		} catch (SocketTimeoutException e) {
			// ignore socket read timeout
		}

Note the // ignore socket read timeout. Now I am not sure if the repeated stack traces (which absolutely overwhelm the output of any other information) is an error on my part, the paho library or not an error at all.

If this is expected behavior, it makes the ssl debugging option almost useless. If it is expected behavior can I ask why it must be so? Can the timeout be made longer so as not to overwhelm any other output?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant