java handwritten RPC (07)-timeout timeout from scratch

"Out of date"

The longest is waiting

We can't wait for one person forever

Like a request

Always wait for a response

timeout handler

java handwriting from scratch RPC (01) based on socket implementation

java handwritten RPC (02)-netty4 from scratch to implement client and server

java handwritten RPC (03) from scratch how to call the server from the client?

java handwritten RPC (04) serialization from scratch

java handwriting from scratch RPC (05) reflection based universal implementation

necessity

Previously, we implemented general rpc, but there is a problem that there is no timeout processing when obtaining the response synchronously.

If the server hangs up or the processing is too slow, the client can't wait all the time.

When the external call exceeds the specified time, it will directly report an error to avoid meaningless resource consumption.

thinking

When called, the start time is reserved.

Check whether it timed out when getting.

At the same time, a thread is created to detect whether there are timeout requests.

realization

thinking

When called, the start time is reserved.

Check whether it timed out when getting.

At the same time, a thread is created to detect whether there are timeout requests.

Timeout detection thread

In order not to affect the performance of normal business, we start another thread to detect whether the call has timed out.

package com.github.houbb.rpc.client.invoke.impl;

import com.github.houbb.heaven.util.common.ArgUtil;
import com.github.houbb.rpc.common.rpc.domain.RpcResponse;
import com.github.houbb.rpc.common.rpc.domain.impl.RpcResponseFactory;
import com.github.houbb.rpc.common.support.time.impl.Times;

import java.util.Map;
import java.util.concurrent.ConcurrentHashMap;

/**
 * Timeout detection thread
 * @author binbin.hou
 * @since 0.0.7
 */
public class TimeoutCheckThread implements Runnable{

    /**
     * Request information
     * @since 0.0.7
     */
    private final ConcurrentHashMap<String, Long> requestMap;

    /**
     * Request information
     * @since 0.0.7
     */
    private final ConcurrentHashMap<String, RpcResponse> responseMap;

    /**
     * newly build
     * @param requestMap  Request Map
     * @param responseMap Result map
     * @since 0.0.7
     */
    public TimeoutCheckThread(ConcurrentHashMap<String, Long> requestMap,
                              ConcurrentHashMap<String, RpcResponse> responseMap) {
        ArgUtil.notNull(requestMap, "requestMap");
        this.requestMap = requestMap;
        this.responseMap = responseMap;
    }

    @Override
    public void run() {
        for(Map.Entry<String, Long> entry : requestMap.entrySet()) {
            long expireTime = entry.getValue();
            long currentTime = Times.time();

            if(currentTime > expireTime) {
                final String key = entry.getKey();
                // The result is set to timeout and removed from the request map
                responseMap.putIfAbsent(key, RpcResponseFactory.timeout());
                requestMap.remove(key);
            }
        }
    }

}

It mainly stores the request and response time. If it times out, the corresponding request will be removed.

Thread start

Start when DefaultInvokeService initializes:

final Runnable timeoutThread = new TimeoutCheckThread(requestMap, responseMap);
Executors.newScheduledThreadPool(1)
                .scheduleAtFixedRate(timeoutThread,60, 60, TimeUnit.SECONDS);

DefaultInvokeService

For the original setting result, the acquisition result does not consider the time. Here, add the corresponding judgment.

Set request time

  • Add request addRequest

The outdated time will be put directly into the map.

Because putting is one operation, the query may be multiple times.

So the time is calculated when it is put in.

@Override
public InvokeService addRequest(String seqId, long timeoutMills) {
    LOG.info("[Client] start add request for seqId: {}, timeoutMills: {}", seqId,
            timeoutMills);
    final long expireTime = Times.time()+timeoutMills;
    requestMap.putIfAbsent(seqId, expireTime);
    return this;
}

Set request results

  • Add response addResponse
  1. If the request information no longer exists in the requestMap, it indicates that it may time out and directly ignore the stored results.

  2. At this time, check whether there is a timeout, and the timeout information will be returned directly.

  3. After the message is put in, notify all other waiting processes.

@Override
public InvokeService addResponse(String seqId, RpcResponse rpcResponse) {
    // 1. Judge whether it is effective
    Long expireTime = this.requestMap.get(seqId);
    // If it is empty, the result may have timed out. The response result will not come until it is removed by the scheduled job. Ignore directly
    if(ObjectUtil.isNull(expireTime)) {
        return this;
    }

    //2. Judge whether the timeout occurs
    if(Times.time() > expireTime) {
        LOG.info("[Client] seqId:{} The information has timed out. The timeout result is returned directly.", seqId);
        rpcResponse = RpcResponseFactory.timeout();
    }

    // Before putting here, you can add judgment.
    // If the seqd must be processed in the request collection, it can be put in. Or ignore and discard directly.
    // Notify all waiting parties
    responseMap.putIfAbsent(seqId, rpcResponse);
    LOG.info("[Client] Get result information, seqId: {}, rpcResponse: {}", seqId, rpcResponse);
    LOG.info("[Client] seqId:{} The message has been put in, notify all waiting parties", seqId);
    // Remove the corresponding requestMap
    requestMap.remove(seqId);
    LOG.info("[Client] seqId:{} remove from request map", seqId);
    synchronized (this) {
        this.notifyAll();
    }
    return this;
}

Get request results

  • Get the corresponding getResponse
  1. If the result exists, the response result is returned directly

  2. Otherwise, wait.

  3. Get results after waiting.

@Override
public RpcResponse getResponse(String seqId) {
    try {
        RpcResponse rpcResponse = this.responseMap.get(seqId);
        if(ObjectUtil.isNotNull(rpcResponse)) {
            LOG.info("[Client] seq {} The corresponding result has been obtained: {}", seqId, rpcResponse);
            return rpcResponse;
        }
        // Enter waiting
        while (rpcResponse == null) {
            LOG.info("[Client] seq {} The corresponding result is empty. Enter wait", seqId);
            // Synchronous wait lock
            synchronized (this) {
                this.wait();
            }
            rpcResponse = this.responseMap.get(seqId);
            LOG.info("[Client] seq {} The corresponding result has been obtained: {}", seqId, rpcResponse);
        }
        return rpcResponse;
    } catch (InterruptedException e) {
        throw new RpcRuntimeException(e);
    }
}

It can be found that the logic of the acquisition part has not changed, because a timeout object will be returned in case of timeout: RpcResponseFactory.timeout();

This is a very simple implementation, as follows:

package com.github.houbb.rpc.common.rpc.domain.impl;

import com.github.houbb.rpc.common.exception.RpcTimeoutException;
import com.github.houbb.rpc.common.rpc.domain.RpcResponse;

/**
 * Response factory class
 * @author binbin.hou
 * @since 0.0.7
 */
public final class RpcResponseFactory {

    private RpcResponseFactory(){}

    /**
     * Timeout exception information
     * @since 0.0.7
     */
    private static final DefaultRpcResponse TIMEOUT;

    static {
        TIMEOUT = new DefaultRpcResponse();
        TIMEOUT.error(new RpcTimeoutException());
    }

    /**
     * Get timeout response results
     * @return Response results
     * @since 0.0.7
     */
    public static RpcResponse timeout() {
        return TIMEOUT;
    }

}

The response result specifies a timeout exception, which will be thrown when the agent processes the result:

RpcResponse rpcResponse = proxyContext.invokeService().getResponse(seqId);
Throwable error = rpcResponse.error();
if(ObjectUtil.isNotNull(error)) {
    throw error;
}
return rpcResponse.result();

Test code

Server

We deliberately add the implementation of the server to sleep, and the others remain unchanged.

public class CalculatorServiceImpl implements CalculatorService {

    public CalculateResponse sum(CalculateRequest request) {
        int sum = request.getOne()+request.getTwo();

        // Deliberately sleeping for 3s
        try {
            TimeUnit.SECONDS.sleep(3);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        return new CalculateResponse(true, sum);
    }

}

client

Set the corresponding timeout to 1S, others remain unchanged:

public static void main(String[] args) {
    // Service configuration information
    ReferenceConfig<CalculatorService> config = new DefaultReferenceConfig<CalculatorService>();
    config.serviceId(ServiceIdConst.CALC);
    config.serviceInterface(CalculatorService.class);
    config.addresses("localhost:9527");
    // Set the timeout to 1S
    config.timeout(1000);

    CalculatorService calculatorService = config.reference();
    CalculateRequest request = new CalculateRequest();
    request.setOne(10);
    request.setTwo(20);

    CalculateResponse response = calculatorService.sum(request);
    System.out.println(response);
}

The log is as follows:

.log.integration.adaptors.stdout.StdOutExImpl' adapter.
[INFO] [2021-10-05 14:59:40.974] [main] [c.g.h.r.c.c.RpcClient.connect] - RPC Service start client
...
[INFO] [2021-10-05 14:59:42.504] [main] [c.g.h.r.c.c.RpcClient.connect] - RPC Service startup, client completion, listening address localhost:9527
[INFO] [2021-10-05 14:59:42.533] [main] [c.g.h.r.c.p.ReferenceProxy.invoke] - [Client] start call remote with request: DefaultRpcRequest{seqId='62e126d9a0334399904509acf8dfe0bb', createTime=1633417182525, serviceId='calc', methodName='sum', paramTypeNames=[com.github.houbb.rpc.server.facade.model.CalculateRequest], paramValues=[CalculateRequest{one=10, two=20}]}
[INFO] [2021-10-05 14:59:42.534] [main] [c.g.h.r.c.i.i.DefaultInvokeService.addRequest] - [Client] start add request for seqId: 62e126d9a0334399904509acf8dfe0bb, timeoutMills: 1000
[INFO] [2021-10-05 14:59:42.535] [main] [c.g.h.r.c.p.ReferenceProxy.invoke] - [Client] start call channel id: 00e04cfffe360988-000004bc-00000000-1178e1265e903c4c-7975626f
...
Exception in thread "main" com.github.houbb.rpc.common.exception.RpcTimeoutException
	at com.github.houbb.rpc.common.rpc.domain.impl.RpcResponseFactory.<clinit>(RpcResponseFactory.java:23)
	at com.github.houbb.rpc.client.invoke.impl.DefaultInvokeService.addResponse(DefaultInvokeService.java:72)
	at com.github.houbb.rpc.client.handler.RpcClientHandler.channelRead0(RpcClientHandler.java:43)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:241)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:138)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
	at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
	at java.lang.Thread.run(Thread.java:748)
...
[INFO] [2021-10-05 14:59:45.615] [nioEventLoopGroup-2-1] [c.g.h.r.c.i.i.DefaultInvokeService.addResponse] - [Client] seqId:62e126d9a0334399904509acf8dfe0bb The information has timed out. The timeout result is returned directly.
[INFO] [2021-10-05 14:59:45.617] [nioEventLoopGroup-2-1] [c.g.h.r.c.i.i.DefaultInvokeService.addResponse] - [Client] Get result information, seqId: 62e126d9a0334399904509acf8dfe0bb, rpcResponse: DefaultRpcResponse{seqId='null', error=com.github.houbb.rpc.common.exception.RpcTimeoutException, result=null}
[INFO] [2021-10-05 14:59:45.617] [nioEventLoopGroup-2-1] [c.g.h.r.c.i.i.DefaultInvokeService.addResponse] - [Client] seqId:62e126d9a0334399904509acf8dfe0bb The message has been put in, notify all waiting parties
[INFO] [2021-10-05 14:59:45.618] [nioEventLoopGroup-2-1] [c.g.h.r.c.i.i.DefaultInvokeService.addResponse] - [Client] seqId:62e126d9a0334399904509acf8dfe0bb remove from request map
[INFO] [2021-10-05 14:59:45.618] [nioEventLoopGroup-2-1] [c.g.h.r.c.c.RpcClient.channelRead0] - [Client] response is :DefaultRpcResponse{seqId='62e126d9a0334399904509acf8dfe0bb', error=null, result=CalculateResponse{success=true, sum=30}}
[INFO] [2021-10-05 14:59:45.619] [main] [c.g.h.r.c.i.i.DefaultInvokeService.getResponse] - [Client] seq 62e126d9a0334399904509acf8dfe0bb The corresponding result has been obtained: DefaultRpcResponse{seqId='null', error=com.github.houbb.rpc.common.exception.RpcTimeoutException, result=null}
...

It can be found that the timeout is abnormal.

deficiencies

The processing of timeout can be extended to two-way. For example, the server can also specify timeout limit to avoid waste of resources.

Summary

In order to facilitate your study, the above source code has been open source:

https://github.com/houbb/rpc

I hope this article is helpful to you. If you like it, you are welcome to like it and forward it.

I'm old ma. I look forward to seeing you again next time.

Tags: Java Distribution rpc Microservices

Posted on Wed, 13 Oct 2021 11:09:57 -0400 by joon