catalogue
background
In order to observe the call of redis conveniently, the general access component of redis is accessed. The project redis sets the socket timeout time to 200ms, and the maximum number of retries configured is 1. It is found that when the project calls redis, some single set statements will take more than 1s, and then the result of executing the command can be obtained. According to the parameter configuration, even if you try again, it will timeout for up to 400ms.
Here are two time-consuming logs in the api on November 25:
RedisClusterClientProxy.printRunCommandTimeoutLog:87 redis cluster cost time: 1608, method name: lpush, key name: asyncnotification:queue RedisClusterClientProxy.printRunCommandTimeoutLog:87 redis cluster cost time: 1609, method name: get, key name: orderInfo:order-10000074
Source code analysis
Observe the Jedis dependency package used by the redis general access component. By viewing the source code, you can find the socket and inputStream variables of the Connection class
this.socket = new Socket(); this.socket.setReuseAddress(true); this.socket.setKeepAlive(true); this.socket.setTcpNoDelay(true); this.socket.setSoLinger(true, 0); this.socket.connect(new InetSocketAddress(this.host, this.port), this.connectionTimeout); this.socket.setSoTimeout(this.soTimeout); this.outputStream = new RedisOutputStream(this.socket.getOutputStream()); this.inputStream = new RedisInputStream(this.socket.getInputStream());
When reading network data, the underlying layer actually uses the SocketInputStream class to read data
AbstractPlainSocketImpl class
protected synchronized InputStream getInputStream() throws IOException {
synchronized (fdLock) {
if (isClosedOrPending())
throw new IOException("Socket Closed");
if (shut_rd)
throw new IOException("Socket input is shutdown");
if (socketInputStream == null)
socketInputStream = new SocketInputStream(this);
}
return socketInputStream;
}read method related to SocketInputStream class
int read(byte b[], int off, int length, int timeout) throws IOException {
int n = 0;
// EOF already encountered
if (eof) {
return -1;
}
// connection reset
if (impl.isConnectionReset()) {
throw new SocketException("Connection reset");
}
// bounds check
if (length <= 0 || off < 0 || off + length > b.length) {
if (length == 0) {
return 0;
}
throw new ArrayIndexOutOfBoundsException();
}
boolean gotReset = false;
Object traceContext = IoTrace.socketReadBegin();
// acquire file descriptor and do the read
FileDescriptor fd = impl.acquireFD();
try {
n = socketRead0(fd, b, off, length, timeout);
if (n > 0) {
return n;
}
} catch (ConnectionResetException rstExc) {
gotReset = true;
} finally {
impl.releaseFD();
IoTrace.socketReadEnd(traceContext, impl.address, impl.port,
timeout, n > 0 ? n : 0);
}
/*
* We receive a "connection reset" but there may be bytes still
* buffered on the socket
*/
if (gotReset) {
traceContext = IoTrace.socketReadBegin();
impl.setConnectionResetPending();
impl.acquireFD();
try {
n = socketRead0(fd, b, off, length, timeout);
if (n > 0) {
return n;
}
} catch (ConnectionResetException rstExc) {
} finally {
impl.releaseFD();
IoTrace.socketReadEnd(traceContext, impl.address, impl.port,
timeout, n > 0 ? n : 0);
}
}
/*
* If we get here we are at EOF, the socket has been closed,
* or the connection has been reset.
*/
if (impl.isClosedOrPending()) {
throw new SocketException("Socket closed");
}
if (impl.isConnectionResetPending()) {
impl.setConnectionReset();
}
if (impl.isConnectionReset()) {
throw new SocketException("Connection reset");
}
eof = true;
return -1;
}The core of this method is actually the call of socketRead0(fd, b, off, length, timeout)
private native int socketRead0(FileDescriptor fd,
byte b[], int off, int len,
int timeout)
throws IOException;The project uses openjdk jdk1.8.0_ 202. socketRead0 is a native method. By downloading the source code of openjdk1.8, we found the relevant implementation in the directory of openjdk\jdk\src\solaris\native\java\net. In the SocketInputStream.c file, the code is as follows:
Java_java_net_SocketInputStream_socketRead0(JNIEnv *env, jobject this,
jobject fdObj, jbyteArray data,
jint off, jint len, jint timeout)
{
char BUF[MAX_BUFFER_LEN];
char *bufP;
jint fd, nread;
if (IS_NULL(fdObj)) {
/* shouldn't this be a NullPointerException? -br */
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketException",
"Socket closed");
return -1;
} else {
fd = (*env)->GetIntField(env, fdObj, IO_fd_fdID);
/* Bug 4086704 - If the Socket associated with this file descriptor
* was closed (sysCloseFD), then the file descriptor is set to -1.
*/
if (fd == -1) {
JNU_ThrowByName(env, "java/net/SocketException", "Socket closed");
return -1;
}
}
/*
* If the read is greater than our stack allocated buffer then
* we allocate from the heap (up to a limit)
*/
if (len > MAX_BUFFER_LEN) {
if (len > MAX_HEAP_BUFFER_LEN) {
len = MAX_HEAP_BUFFER_LEN;
}
bufP = (char *)malloc((size_t)len);
if (bufP == NULL) {
bufP = BUF;
len = MAX_BUFFER_LEN;
}
} else {
bufP = BUF;
}
if (timeout) {
nread = NET_Timeout(fd, timeout);
if (nread <= 0) {
if (nread == 0) {
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketTimeoutException",
"Read timed out");
} else if (nread == JVM_IO_ERR) {
if (errno == EBADF) {
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketException", "Socket closed");
} else if (errno == ENOMEM) {
JNU_ThrowOutOfMemoryError(env, "NET_Timeout native heap allocation failed");
} else {
NET_ThrowByNameWithLastError(env, JNU_JAVANETPKG "SocketException",
"select/poll failed");
}
} else if (nread == JVM_IO_INTR) {
JNU_ThrowByName(env, JNU_JAVAIOPKG "InterruptedIOException",
"Operation interrupted");
}
if (bufP != BUF) {
free(bufP);
}
return -1;
}
}
nread = NET_Read(fd, bufP, len);
if (nread <= 0) {
if (nread < 0) {
switch (errno) {
case ECONNRESET:
case EPIPE:
JNU_ThrowByName(env, "sun/net/ConnectionResetException",
"Connection reset");
break;
case EBADF:
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketException",
"Socket closed");
break;
case EINTR:
JNU_ThrowByName(env, JNU_JAVAIOPKG "InterruptedIOException",
"Operation interrupted");
break;
default:
NET_ThrowByNameWithLastError(env,
JNU_JAVANETPKG "SocketException", "Read failed");
}
}
} else {
(*env)->SetByteArrayRegion(env, data, off, nread, (jbyte *)bufP);
}
if (bufP != BUF) {
free(bufP);
}
return nread;
}Data is read through NET_Timeout (fd, timeout) is implemented in Linux_ Net was found in the close. C file_ Implementation of timeout:
int NET_Timeout(int s, long timeout) {
long prevtime = 0, newtime;
struct timeval t;
fdEntry_t *fdEntry = getFdEntry(s);
/*
* Check that fd hasn't been closed.
*/
if (fdEntry == NULL) {
errno = EBADF;
return -1;
}
/*
* Pick up current time as may need to adjust timeout
*/
if (timeout > 0) {
gettimeofday(&t, NULL);
prevtime = t.tv_sec * 1000 + t.tv_usec / 1000;
}
for(;;) {
struct pollfd pfd;
int rv;
threadEntry_t self;
/*
* Poll the fd. If interrupted by our wakeup signal
* errno will be set to EBADF.
*/
pfd.fd = s;
pfd.events = POLLIN | POLLERR;
startOp(fdEntry, &self);
rv = poll(&pfd, 1, timeout);
endOp(fdEntry, &self);
/*
* If interrupted, adjust the timeout. If timeout
* Expired returns 0 (indicating that the timeout has expired).
*/
if (rv < 0 && errno == EINTR) {
if (timeout > 0) {
gettimeofday(&t, NULL);
newtime = t.tv_sec * 1000 + t.tv_usec / 1000;
timeout -= newtime - prevtime;
if (timeout <= 0) {
return 0;
}
prevtime = newtime;
}
} else {
return rv;
}
}
}The key point in the code is poll (& PFD, 1, timeout). Poll is a function in the character device driver in linux. It is used to hang the current file pointer to the wait defined inside the device.
It's easy to understand. In fact, this time is the longest blocking time between reading data. If I return part of the data within 200ms each time in the case of network jitter, I won't timeout all the time.
Reproduce phenomenon according to principle
Because it is difficult to send some data with redis control interval, we can find another way. http reads network data with java io class. In fact, the underlying layer also uses SocketInputStream to read data.
private static Logger LOGGER = LoggerFactory.getLogger(HomeController.class);
@RequestMapping("/testSocketTimeout")
public void testSocketTimeout(HttpServletRequest request , HttpServletResponse response) throws Exception {
PrintWriter writer = response.getWriter();
while (true){
writer.print("hello world! I'm niwanjia");
writer.flush();
Thread.sleep(2000);
LOGGER.info("testSocketTimeout");
}
}This code sends a piece of data every 2s and sends it circularly. When the network is bad, the received data is intermittent. Another test is used to send the request and directly debug the test:
@Test
public void tetsHttpClientHttp() throws IOException {
RequestConfig requestConfig = RequestConfig.custom()
.setConnectTimeout(1000)
.setSocketTimeout(3000)
.setConnectionRequestTimeout(1000)
.build();
CloseableHttpClient httpClient = HttpClientBuilder.create().setDefaultRequestConfig(requestConfig).build();
HttpGet httpGet = new HttpGet("http://test.com/mock/testSocketTimeout");
CloseableHttpResponse response =httpClient.execute(httpGet);
HttpEntity responseEntity = response.getEntity();
if (responseEntity != null) {
System.out.println("The response content is:" + EntityUtils.toString(responseEntity));
}
}Client returned results:
The response content is:hello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjiahello world! I'm niwanjia
When we modify socketTimeout to 1000, we can throw java.net.SocketTimeoutException: Read timed out exception after verification
java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141)
reference resources
https://www.cnblogs.com/chengxiansheng/p/13232686.html