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

UnixDomainSocket connection returns error from server #528

Closed
pandyah opened this issue Sep 20, 2021 · 7 comments
Closed

UnixDomainSocket connection returns error from server #528

pandyah opened this issue Sep 20, 2021 · 7 comments
Labels
bug Something isn't working

Comments

@pandyah
Copy link

pandyah commented Sep 20, 2021

Hi,

While trying to connect to PARSEC server using Java 16 java.net.UnixDomainSocketAddress, PARSEC server returns an error as soon as the client is connected to the server. This is without even sending any data to the SocketChannel. Also it returns error status 15 ConnectionError - Generic input/output error. Returned buffer is
10 a7 c0 5e 1e 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 f 0 0 0

Below are the error details.

[WARN  parsec_interface::requests::response_status] Conversion from Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } to ResponseStatus::ConnectionError.
[WARN  parsec_interface::requests::response_status] The WouldBlock error might mean that the connection timed out. Try in increase the timeout length.
[ERROR parsec_service::front::front_end] Failed to read request;

Best regards,
Hitesh

@hug-dev hug-dev added the bug Something isn't working label Sep 20, 2021
@hug-dev
Copy link
Member

hug-dev commented Sep 20, 2021

Hi Hitesh,

Thanks for your bug report. That is indeed weird and not something I have seen in the past!
If Parsec returns something it means that it accepted a connection channel with the client. The error might occur because after the connection is accepted, nothing is sent from the client for a too long time (more than 200 ms by default).

A few ideas:

  • can you try to set the log_level field in the configuration as "trace", set log_error_details = true and post the full Parsec logs?
  • can you try to see if the same error happens further in time if you increase the timeout field?

On the client side, in Java, after you connect do you send anything? Connections to the socket are meant to be short-lived, in Rust and Go we do the following for each operation the client wants to perform:

  1. Open a new connection to the Parsec socket
  2. Create the request payload
  3. Write the payload to the connection (that then happens very shortly after opening the connection and should not last too long)
  4. Read the response from Parsec
  5. Close the connection (at the end or if any error occured).

It might be the case that we totally omitted this from our docs or something is not clear!

@pandyah
Copy link
Author

pandyah commented Sep 20, 2021

Thanks for the quick response. Please find attached the error that is immediately coming after SocketChannel.open(socketAddress). The connect socket itself is giving an error. Also, there is no timeout setting for java UnixDomainSockets and therefore cannot set it in the SocketChannel. However, have increased the timeout in the server to 1200.

[listener]
listener_type = "DomainSocket"
timeout = 1200 # in milliseconds
socket_path = "./parsec.sock"

//Trace at Server

[TRACE parsec_service::front::front_end] handle_request ingress
[WARN  parsec_interface::requests::response_status] Conversion from Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } to ResponseStatus::ConnectionError.
[WARN  parsec_interface::requests::response_status] The WouldBlock error might mean that the connection timed out. Try in increase the timeout length.
[ERROR parsec_service::front::front_end] Failed to read request; Error: generic input/output error
[TRACE parsec] handle_request egress

Below is the code that is used.

		Path socketFile = Path.of("/home/hitesh/quickstart-0.7.0-linux_x86/parsec.sock");
		UnixDomainSocketAddress socketAddress = UnixDomainSocketAddress.of(socketFile);
		clientChannel = SocketChannel.open(socketAddress);

		if (clientChannel.isConnected()) {
			System.out.println("Channel open: " + clientChannel.isOpen());
			System.out.println("Channel blocking: " + clientChannel.isBlocking());
			System.out.println("Socket Connected: " + clientChannel.isConnected());
			System.out.println("Is Connection Pending: " + clientChannel.isConnectionPending());
			
			readFromSocket();
		}

The java console gives the following

Channel open: true
Channel blocking: true
Socket Connected: true
Is Connection Pending: false

Read from Socket
4
32
byte Array Length: 36
10 a7 c0 5e 1e 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 0f 00 00 00

@hug-dev
Copy link
Member

hug-dev commented Sep 21, 2021

I was able to reproduce the bug starting Parsec from the quickstart guide and using the following Java file (improved from the HelloWorld basic file since I have not done Java in a long long time):

root@d55705680706:/tmp/parsec_test# cat HelloWorldApp.java
/**
 * The HelloWorldApp class implements an application that
 * simply prints "Hello World!" to standard output.
 */

import java.nio.ByteBuffer;
import java.nio.channels.SocketChannel;
import java.net.UnixDomainSocketAddress;
import java.nio.file.Path;
import java.io.IOException;

class HelloWorldApp {
        public static void main(String[] args) {
                System.out.println("Hello World!"); // Display the string.
                Path socketFile = Path.of("/tmp/quickstart-0.7.0-linux_x86/parsec.sock");
                UnixDomainSocketAddress socketAddress = UnixDomainSocketAddress.of(socketFile);
                try {
                        SocketChannel clientChannel = SocketChannel.open(socketAddress);

                        if (clientChannel.isConnected()) {
                                System.out.println("Channel open: " + clientChannel.isOpen());
                                System.out.println("Channel blocking: " + clientChannel.isBlocking());
                                System.out.println("Socket Connected: " + clientChannel.isConnected());
                                System.out.println("Is Connection Pending: " + clientChannel.isConnectionPending());

                                ByteBuffer buff = ByteBuffer.allocate(100);
                                int bytes_read = clientChannel.read(buff);
                                bytes_read += clientChannel.read(buff);
                                System.out.println("bytes read: " + bytes_read);
                                buff.rewind();
                                while (buff.hasRemaining()) {
                                        System.out.print(" " + buff.get());
                                }
                                System.out.println(" ");
                        }
                }
                catch(IOException e) {
                        e.printStackTrace();
                }
        }
}

I see the exact same error message and bytes returned. This is a Parsec error message response with empty bodies, the Ping opcode and the Communication Error status.

However, I can see a difference if I change the timeout on Parsec side. For example setting a 5 seconds timeout (timeout = 5000 # in milliseconds), I first see:

[TRACE parsec_service::front::front_end] handle_request ingress

and then exactly 5 seconds after:

[WARN  parsec_interface::requests::response_status] Conversion from Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } to ResponseStatus::ConnectionError.
[WARN  parsec_interface::requests::response_status] The WouldBlock error might mean that the connection timed out. Try in increase the timeout length.
[ERROR parsec_service::front::front_end] Failed to read request; Error: generic input/output error
[TRACE parsec] handle_request egress

Which lets me think that this is a timeout issue: Parsec is waiting for the timeout time that some data is sent over the socket by the client and after that time sends back an error response.

Are you experiencing the same if you increase the timeout on Parsec side to 5, 10 seconds? Or does it still immediately fail?

@pandyah
Copy link
Author

pandyah commented Sep 22, 2021

Thanks Hugues. That is a good observation. You are right, I am also able to see the error after 5 seconds timeout.
Also, even if you send anything on the socket with even a wrong magic number, it is not processed and only the error is returned after timeout.

@hug-dev
Copy link
Member

hug-dev commented Sep 22, 2021

Also, even if you send anything on the socket with even a wrong magic number, it is not processed and only the error is returned after timeout.

I tried that as well and observed the same behaviour until I remembered I need to call rewind on the ByteBuffer before sending it 😄
With the following code I have the expected response from Parsec, directly, without waiting for the timeout:

/**
 * The HelloWorldApp class implements an application that
 * simply prints "Hello World!" to standard output.
 */

import java.nio.ByteBuffer;
import java.nio.channels.SocketChannel;
import java.net.UnixDomainSocketAddress;
import java.nio.file.Path;
import java.io.IOException;

class HelloWorldApp {
        public static void main(String[] args) {
                System.out.println("Hello World!"); // Display the string.
                Path socketFile = Path.of("/tmp/quickstart-0.7.0-linux_x86/parsec.sock");
                UnixDomainSocketAddress socketAddress = UnixDomainSocketAddress.of(socketFile);
                try {
                        SocketChannel clientChannel = SocketChannel.open(socketAddress);

                        if (clientChannel.isConnected()) {
                                System.out.println("Channel open: " + clientChannel.isOpen());
                                System.out.println("Channel blocking: " + clientChannel.isBlocking());
                                System.out.println("Socket Connected: " + clientChannel.isConnected());
                                System.out.println("Is Connection Pending: " + clientChannel.isConnectionPending());

                                ByteBuffer write_buff = ByteBuffer.allocate(4);
                                //write_buff.put((byte)0x10);
                                write_buff.put((byte)0x11);
                                write_buff.put((byte)0xA7);
                                write_buff.put((byte)0xC0);
                                write_buff.put((byte)0x5E);
                                write_buff.rewind();
                                int bytes_written = clientChannel.write(write_buff);
                                System.out.println("bytes written: " + bytes_written);

                                ByteBuffer read_buff = ByteBuffer.allocate(100);
                                int bytes_read = clientChannel.read(read_buff);
                                bytes_read += clientChannel.read(read_buff);
                                System.out.println("bytes read: " + bytes_read);
                                read_buff.rewind();
                                while (read_buff.hasRemaining()) {
                                        System.out.print(" " + read_buff.get());
                                }
                                System.out.println(" ");
                        }
                }
                catch(IOException e) {
                        e.printStackTrace();
                }
        }
}

Console client side:

root@d55705680706:/tmp/parsec_test# java HelloWorldApp
Hello World!
Channel open: true
Channel blocking: true
Socket Connected: true
Is Connection Pending: false
bytes written: 4
bytes read: 35
 16 -89 -64 94 30 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 17 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0

On the Parsec side:

[TRACE parsec_service::front::front_end] handle_request ingress
[ERROR parsec_interface::requests::common::wire_header_1_0] Expected magic number 1589683984, got 1589683985
[ERROR parsec_service::front::front_end] Failed to read request; Error: constant fields in header are invalid
[TRACE parsec] handle_request egress

Did you think about rewinding yourself? Do you have somehow similar code?

@pandyah
Copy link
Author

pandyah commented Sep 23, 2021

Thanks Hugues. Yes, I had missed rewind over several trials. :-) After increasing the timeout, it seems to be sending the response properly. Please find below the code that I am using and the console output.

Thanks & Regards.

package com.parsec.test;

import java.io.IOException;
import java.net.UnixDomainSocketAddress;
import java.nio.ByteBuffer;
import java.nio.channels.SocketChannel;
import java.nio.file.Path;

public class ParsecClientSocket {

	private static SocketChannel clientChannel;

	public static void main(String[] args) throws IOException, InterruptedException {

		Path socketFile = Path.of("/home/hitesh/quickstart-0.7.0-linux_x86/parsec.sock");
		UnixDomainSocketAddress socketAddress = UnixDomainSocketAddress.of(socketFile);
		clientChannel = SocketChannel.open(socketAddress);

		if (clientChannel.isConnected()) {
			System.out.println("Channel open: " + clientChannel.isOpen());
			System.out.println("Channel blocking: " + clientChannel.isBlocking());
			System.out.println("Socket Connected: " + clientChannel.isConnected());
			System.out.println("Is Connection Pending: " + clientChannel.isConnectionPending());

			// readFromSocket();
		}

		if (clientChannel.isConnected()) {
			writeToSocket();
		}

		if (clientChannel.isConnected()) {
			readFromSocket();
		}

		clientChannel.close();
	}

	public static void writeToSocket() {

		System.out.println("Writing to Socket: ");
		ByteBuffer buf = getHeader();

		// Header length is fixed to 36
		printBuffer(buf, 36);

		buf.rewind(); // or flip
		int bytesWritten = 0;
		try {
			bytesWritten = clientChannel.write(buf);
		} catch (IOException e) {
			System.out.println("Error while writing to socket");
			e.printStackTrace();
		}
		System.out.println("Bytes written to socket: " + bytesWritten);
	}

	public static void readFromSocket() {

		// Read Response
		System.out.println("Read from Socket: ");
		ByteBuffer readBuf = ByteBuffer.allocate(1024);
		readBuf.clear();

		int total = 0;
		int bytesRead = 0;
		try {
			while ((bytesRead = clientChannel.read(readBuf)) != -1) {
				total = total + bytesRead;
				System.out.println("Bytes Read: " + bytesRead);
			}
		} catch (IOException e) {
			System.out.println("Error while reading from socket");
			e.printStackTrace();
		}

		ByteBuffer finalBuf = ByteBuffer.allocate(total);
		printBuffer(readBuf, total);

	}

	public static ByteBuffer getHeader() {

		// Magic Number - 1589683984
		ByteBuffer bbuf = ByteBuffer.allocate(36);
		bbuf.put((byte) 0x10);
		bbuf.put((byte) 0xa7);
		bbuf.put((byte) 0xc0);
		bbuf.put((byte) 0x5e);
		bbuf.put((byte) 0x1e); // Header Size
		bbuf.put((byte) 0x00); // Header Size
		bbuf.put((byte) 0x01); // Major
		bbuf.put((byte) 0x00); // Minor
		bbuf.put((byte) 0x00); // Flag
		bbuf.put((byte) 0x00); // Flag
		bbuf.put((byte) 0x00); // Empty
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Session
		bbuf.put((byte) 0x00); // Content-type
		bbuf.put((byte) 0x00); // Accept
		bbuf.put((byte) 0x00); // Auth
		bbuf.put((byte) 0x00); // Content Length
		bbuf.put((byte) 0x00); // Content Length
		bbuf.put((byte) 0x00); // Content Length
		bbuf.put((byte) 0x00); // Content Length
		bbuf.put((byte) 0x00); // Auth length
		bbuf.put((byte) 0x00); // Auth length
		bbuf.put((byte) 0x01); // Opcode
		bbuf.put((byte) 0x00); // Opcode
		bbuf.put((byte) 0x00); // Opcode
		bbuf.put((byte) 0x00); // Opcode
		bbuf.put((byte) 0x00); // Status
		bbuf.put((byte) 0x00); // Status
		bbuf.put((byte) 0x00); // Reserved
		bbuf.put((byte) 0x00); // Reserved
		return bbuf;

	}

	public static void printBuffer(ByteBuffer buf, int len) {

		byte[] byAr = buf.array();
		System.out.println("byte Array Length: " + len);

		for (int i = 0; i < len; i++) {
			System.out.print(
					Integer.toHexString(0xFF & byAr[i]).length() == 1 ? "0" + Integer.toHexString(0xFF & byAr[i]) + " "
							: Integer.toHexString(0xFF & byAr[i]) + " ");
		}
		System.out.println(" ");
	}

}

Console Output:

Channel open: true
Channel blocking: true
Socket Connected: true
Is Connection Pending: false
Writing to Socket: 
byte Array Length: 36
10 a7 c0 5e 1e 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00  
Bytes written to socket: 36
Read from Socket: 
Bytes Read: 7
Bytes Read: 31
byte Array Length: 38
10 a7 c0 5e 1e 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00 00 00 01 00 00 00 00 00 00 00 08 01  

On Parsec side:

[TRACE parsec_service::front::front_end] handle_request ingress
[INFO  parsec_service::front::front_end] New request received without authentication
[TRACE parsec_service::back::dispatcher] dispatch_request ingress
[TRACE parsec_service::back::backend_handler] execute_request ingress
[TRACE parsec_service::providers::core] ping ingress
[TRACE parsec_service::back::backend_handler] ping egress
[TRACE parsec_service::back::dispatcher] execute_request egress
[TRACE parsec_service::front::front_end] dispatch_request egress
[INFO  parsec_service::front::front_end] Response sent back from request without authentication
[TRACE parsec] handle_request egress

In case of wrong Magic number:
Console output:

Channel open: true
Channel blocking: true
Socket Connected: true
Is Connection Pending: false
Writing to Socket: 
byte Array Length: 36
10 37 c0 5e 1e 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00  
Bytes written to socket: 36
Read from Socket: 
Bytes Read: 36
Error while reading from socket
java.net.SocketException: Connection reset
	at java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:394)
	at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:426)
	at com.parsec.test.ParsecClientSocket.readFromSocket(ParsecClientSocket.java:69)
	at com.parsec.test.ParsecClientSocket.main(ParsecClientSocket.java:34)
byte Array Length: 36
10 a7 c0 5e 1e 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 11 00 00 00

On Parsec side:

[TRACE parsec_service::front::front_end] handle_request ingress
[ERROR parsec_interface::requests::common::wire_header_1_0] Expected magic number 1589683984, got 1589655312
[ERROR parsec_service::front::front_end] Failed to read request; Error: constant fields in header are invalid
[TRACE parsec] handle_request egress

@hug-dev
Copy link
Member

hug-dev commented Sep 23, 2021

Nice, perfect! Glad I was able to help 😃

@hug-dev hug-dev closed this as completed Sep 23, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants