diff --git a/common/queue/src/main/java/org/thingsboard/server/queue/common/DefaultTbQueueRequestTemplate.java b/common/queue/src/main/java/org/thingsboard/server/queue/common/DefaultTbQueueRequestTemplate.java index bfda553538..d5179385e6 100644 --- a/common/queue/src/main/java/org/thingsboard/server/queue/common/DefaultTbQueueRequestTemplate.java +++ b/common/queue/src/main/java/org/thingsboard/server/queue/common/DefaultTbQueueRequestTemplate.java @@ -36,10 +36,12 @@ import javax.annotation.Nullable; import java.util.List; import java.util.UUID; import java.util.concurrent.ConcurrentHashMap; -import java.util.concurrent.ConcurrentMap; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; +import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeoutException; +import java.util.concurrent.locks.Lock; +import java.util.concurrent.locks.ReentrantLock; @Slf4j public class DefaultTbQueueRequestTemplate extends AbstractTbQueueTemplate @@ -48,16 +50,15 @@ public class DefaultTbQueueRequestTemplate requestTemplate; private final TbQueueConsumer responseTemplate; - final ConcurrentMap> pendingRequests; + final ConcurrentHashMap> pendingRequests = new ConcurrentHashMap<>(); final boolean internalExecutor; final ExecutorService executor; - final long maxRequestTimeout; + final long maxRequestTimeoutNs; final long maxPendingRequests; final long pollInterval; - volatile long tickTs = 0L; - volatile long tickSize = 0L; volatile boolean stopped = false; - long nextCleanupMs = 0L; + long nextCleanupNs = 0L; + private final Lock cleanerLock = new ReentrantLock(); private MessagesStats messagesStats; @@ -72,8 +73,7 @@ public class DefaultTbQueueRequestTemplate(); - this.maxRequestTimeout = maxRequestTimeout; + this.maxRequestTimeoutNs = TimeUnit.MILLISECONDS.toNanos(maxRequestTimeout); this.maxPendingRequests = maxPendingRequests; this.pollInterval = pollInterval; this.internalExecutor = (executor == null); @@ -88,7 +88,6 @@ public class DefaultTbQueueRequestTemplate responses = doPoll(); //poll js responses //if (responses.size() > 0) { @@ -113,25 +112,36 @@ public class DefaultTbQueueRequestTemplate { - if (value.expTime < tickTs) { - ResponseMetaData staleRequest = pendingRequests.remove(key); - if (staleRequest != null) { - setTimeoutException(key, staleRequest, tickTs); + tryCleanStaleRequests(); + } + + private boolean tryCleanStaleRequests() { + if (!cleanerLock.tryLock()) { + return false; + } + try { + log.trace("tryCleanStaleRequest..."); + final long currentNs = getCurrentClockNs(); + if (nextCleanupNs < currentNs) { + pendingRequests.forEach((key, value) -> { + if (value.expTime < currentNs) { + ResponseMetaData staleRequest = pendingRequests.remove(key); + if (staleRequest != null) { + setTimeoutException(key, staleRequest, currentNs); + } } - } - }); - setupNextCleanup(); + }); + setupNextCleanup(); + } + } finally { + cleanerLock.unlock(); } + return true; } void setupNextCleanup() { - nextCleanupMs = tickTs + maxRequestTimeout; - log.info("setupNextCleanup {}", nextCleanupMs); + nextCleanupNs = getCurrentClockNs() + maxRequestTimeoutNs; + log.info("setupNextCleanup {}", nextCleanupNs); } List doPoll() { @@ -146,11 +156,11 @@ public class DefaultTbQueueRequestTemplate staleRequest, long tickTs) { - if (tickTs >= staleRequest.getSubmitTime() + staleRequest.getTimeout()) { - log.info("Request timeout detected, tickTs [{}], {}, key [{}]", tickTs, staleRequest, key); + void setTimeoutException(UUID key, ResponseMetaData staleRequest, long currentNs) { + if (currentNs >= staleRequest.getSubmitTime() + staleRequest.getTimeout()) { + log.info("Request timeout detected, currentNs [{}], {}, key [{}]", currentNs, staleRequest, key); } else { - log.error("Request timeout detected, tickTs [{}], {}, key [{}]", tickTs, staleRequest, key); + log.error("Request timeout detected, currentNs [{}], {}, key [{}]", currentNs, staleRequest, key); } staleRequest.future.setException(new TimeoutException()); @@ -197,23 +207,31 @@ public class DefaultTbQueueRequestTemplate send(Request request) { - if (tickSize > maxPendingRequests) { + if (pendingRequests.mappingCount() >= maxPendingRequests) { + log.warn("Pending request map is full [{}]! Consider to increase maxPendingRequests or increase processing performance", maxPendingRequests); return Futures.immediateFailedFuture(new RuntimeException("Pending request map is full!")); } UUID requestId = UUID.randomUUID(); request.getHeaders().put(REQUEST_ID_HEADER, uuidToBytes(requestId)); request.getHeaders().put(RESPONSE_TOPIC_HEADER, stringToBytes(responseTemplate.getTopic())); - long currentTime = getCurrentTime(); - request.getHeaders().put(REQUEST_TIME, longToBytes(currentTime)); + request.getHeaders().put(REQUEST_TIME, longToBytes(getCurrentTimeMs())); + long currentClockNs = getCurrentClockNs(); SettableFuture future = SettableFuture.create(); - ResponseMetaData responseMetaData = new ResponseMetaData<>(tickTs + maxRequestTimeout, future, currentTime, maxRequestTimeout); - log.info("pending {}", responseMetaData); - pendingRequests.putIfAbsent(requestId, responseMetaData); + ResponseMetaData responseMetaData = new ResponseMetaData<>(currentClockNs + maxRequestTimeoutNs, future, currentClockNs, maxRequestTimeoutNs); + log.info("pending {}", responseMetaData); //TODO trace + if (pendingRequests.putIfAbsent(requestId, responseMetaData) != null) { + log.warn("Pending request already exists [{}]!", maxPendingRequests); + return Futures.immediateFailedFuture(new RuntimeException("Pending request already exists !" + requestId)); + } sendToRequestTemplate(request, requestId, future, responseMetaData); return future; } - long getCurrentTime() { + long getCurrentClockNs() { + return System.nanoTime(); //MONOTONIC clock instead wall clock + } + + long getCurrentTimeMs() { //Wall clock to send Ts to the an external service return System.currentTimeMillis(); } @@ -261,8 +279,8 @@ public class DefaultTbQueueRequestTemplate { log.info("currentTime={}", currentTime.get()); return currentTime.get(); - }).given(inst).getCurrentTime(); + }).given(inst).getCurrentClockNs(); inst.init(); inst.setupNextCleanup(); willReturn(Collections.emptyList()).given(inst).doPoll(); willDoNothing().given(inst).processResponse(any()); //when - for (int i = 0; i <= inst.maxRequestTimeout*2; i++) { - currentTime.incrementAndGet(); + long stepNs = TimeUnit.MILLISECONDS.toNanos(1); + for (long i = 0; i <= inst.maxRequestTimeoutNs * 2; i = i + stepNs) { + currentTime.addAndGet(stepNs); assertFalse(inst.send(getRequestMsgMock()).isDone()); //SettableFuture future - pending only - if (i % (inst.maxRequestTimeout * 3 / 2) == 0) { + if (i % (inst.maxRequestTimeoutNs * 3 / 2) == 0) { inst.fetchAndProcessResponses(); } }