From 7b4acdacdca67ced8a3ee5df2b3b20fc938ba8b3 Mon Sep 17 00:00:00 2001 From: Jason Joo Date: Fri, 18 Sep 2020 14:15:49 +0800 Subject: [PATCH] Make TimeUtil have multiple running states: - IDLE: Direct invocation state for idle conditions. - RUNNING: Legacy mode for busy conditions. - REQUEST: Temporary state from IDLE to RUNNING. Through this design TimeUtil won't cost much in idle systems any more. Signed-off-by: Jason Joo --- .../alibaba/csp/sentinel/util/TimeUtil.java | 194 ++++++++++++++++-- .../csp/sentinel/util/TimeUtilTest.java | 111 ++++++++++ 2 files changed, 290 insertions(+), 15 deletions(-) create mode 100644 sentinel-core/src/test/java/com/alibaba/csp/sentinel/util/TimeUtilTest.java diff --git a/sentinel-core/src/main/java/com/alibaba/csp/sentinel/util/TimeUtil.java b/sentinel-core/src/main/java/com/alibaba/csp/sentinel/util/TimeUtil.java index a51276a087..a4c533b501 100755 --- a/sentinel-core/src/main/java/com/alibaba/csp/sentinel/util/TimeUtil.java +++ b/sentinel-core/src/main/java/com/alibaba/csp/sentinel/util/TimeUtil.java @@ -15,38 +15,202 @@ */ package com.alibaba.csp.sentinel.util; +import java.util.List; import java.util.concurrent.TimeUnit; +import com.alibaba.csp.sentinel.log.RecordLog; +import com.alibaba.csp.sentinel.slots.statistic.base.LeapArray; +import com.alibaba.csp.sentinel.slots.statistic.base.LongAdder; +import com.alibaba.csp.sentinel.slots.statistic.base.WindowWrap; +import com.alibaba.csp.sentinel.util.function.Tuple2; + /** * Provides millisecond-level time of OS. + *

+ * Here we should see that not all the time TimeUtil should + * keep looping 1_000 times every second (Actually about 800/s due to some losses). + * 

+ * * In idle conditions it just acts as System.currentTimeMillis();
+ * * In busy conditions (significantly more than 1_000/s) it keeps loop to reduce costs.
+ *
+ * For detail design and proposals please goto + * https://github.com/alibaba/Sentinel/issues/1702 * * @author qinan.qn + * @author jason */ -public final class TimeUtil { +public final class TimeUtil implements Runnable { + private static final long CHECK_INTERVAL = 3000; + private static final long HITS_LOWER_BOUNDARY = 800; + private static final long HITS_UPPER_BOUNDARY = 1200; + + public static enum STATE { + IDLE, PREPARE, RUNNING; + } + private static class Statistic { + private LongAdder writes = new LongAdder(); + private LongAdder reads = new LongAdder(); + public LongAdder getWrites() { + return writes; + } + public LongAdder getReads() { + return reads; + } + } + private static TimeUtil INSTANCE; - private static volatile long currentTimeMillis; + private volatile long currentTimeMillis; + private volatile STATE state = STATE.IDLE; + + private LeapArray statistics; + + // thread private variables + private long lastCheck = 0; static { - currentTimeMillis = System.currentTimeMillis(); - Thread daemon = new Thread(new Runnable() { + INSTANCE = new TimeUtil(); + } + + public TimeUtil() { + this.statistics = new LeapArray(3, 3000) { + @Override - public void run() { - while (true) { - currentTimeMillis = System.currentTimeMillis(); - try { - TimeUnit.MILLISECONDS.sleep(1); - } catch (Throwable e) { - - } - } + public Statistic newEmptyBucket(long timeMillis) { + return new Statistic(); } - }); + + @Override + protected WindowWrap resetWindowTo(WindowWrap windowWrap, long startTime) { + Statistic val = windowWrap.value(); + val.getReads().reset(); + val.getWrites().reset(); + windowWrap.resetTo(startTime); + return windowWrap; + } + }; + this.currentTimeMillis = System.currentTimeMillis(); + this.lastCheck = this.currentTimeMillis; + Thread daemon = new Thread(this); daemon.setDaemon(true); daemon.setName("sentinel-time-tick-thread"); daemon.start(); } + + @Override + public void run() { + while (true) { + this.check(); + if (this.state == STATE.RUNNING) { + this.currentTimeMillis = System.currentTimeMillis(); + this.statistics.currentWindow(this.currentTimeMillis).value().getWrites().increment(); + try { + TimeUnit.MILLISECONDS.sleep(1); + } catch (Throwable e) { + } + continue; + } + if (this.state == STATE.IDLE) { + try { + TimeUnit.MILLISECONDS.sleep(300); + } catch (Throwable e) { + } + continue; + } + if (this.state == STATE.PREPARE) { + RecordLog.info("TimeUtil switches to RUNNING"); + this.currentTimeMillis = System.currentTimeMillis(); + this.state = STATE.RUNNING; + continue; + } + } + } + + /** + * Current running state + * + * @return + */ + public STATE getState() { + return state; + } + + /** + * Current qps statistics (including reads and writes request) + * excluding current working time window for accurate result. + * + * @param now + * @return + */ + public Tuple2 currentQps(long now) { + List> list = this.statistics.listAll(); + long reads = 0; + long writes = 0; + int cnt = 0; + for (WindowWrap windowWrap : list) { + if (windowWrap.isTimeInWindow(now)) { + continue; + } + cnt ++; + reads += windowWrap.value().getReads().longValue(); + writes += windowWrap.value().getWrites().longValue(); + } + if (cnt < 1) { + return new Tuple2(0L, 0L); + } + return new Tuple2(reads / cnt, writes / cnt); + } + + /** + * Check and operate the state if necessary. + * ATTENTION: It's called in daemon thread. + */ + private void check() { + long now = currentTime(true); + // every period + if (now - this.lastCheck < CHECK_INTERVAL) { + return; + } + this.lastCheck = now; + Tuple2 qps = currentQps(now); + if (this.state == STATE.IDLE && qps.r1 > HITS_UPPER_BOUNDARY) { + RecordLog.info("TimeUtil switches to PREPARE for better performance, reads={}/s, writes={}/s", qps.r1, qps.r2); + this.state = STATE.PREPARE; + } else if (this.state == STATE.RUNNING && qps.r1 < HITS_LOWER_BOUNDARY) { + RecordLog.info("TimeUtil switches to IDLE due to not enough load, reads={}/s, writes={}/s", qps.r1, qps.r2); + this.state = STATE.IDLE; + } + } + + private long currentTime(boolean innerCall) { + long now = this.currentTimeMillis; + Statistic val = this.statistics.currentWindow(now).value(); + if (!innerCall) { + val.getReads().increment(); + } + if (this.state == STATE.IDLE || this.state == STATE.PREPARE) { + now = System.currentTimeMillis(); + this.currentTimeMillis = now; + if (!innerCall) { + val.getWrites().increment(); + } + } + return now; + } + + /** + * Current timestamp in milliseconds. + * + * @return + */ + public long getTime() { + return this.currentTime(false); + } + + public static TimeUtil instance() { + return INSTANCE; + } public static long currentTimeMillis() { - return currentTimeMillis; + return INSTANCE.getTime(); } } diff --git a/sentinel-core/src/test/java/com/alibaba/csp/sentinel/util/TimeUtilTest.java b/sentinel-core/src/test/java/com/alibaba/csp/sentinel/util/TimeUtilTest.java new file mode 100644 index 0000000000..9c3568a9d5 --- /dev/null +++ b/sentinel-core/src/test/java/com/alibaba/csp/sentinel/util/TimeUtilTest.java @@ -0,0 +1,111 @@ +/* + * Copyright 1999-2020 Alibaba Group Holding Ltd. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.alibaba.csp.sentinel.util; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertTrue; + +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicInteger; + +import org.junit.Before; +import org.junit.Test; + +import com.alibaba.csp.sentinel.log.RecordLog; +import com.alibaba.csp.sentinel.util.function.Tuple2; + +/** + * @author jason + * + */ +public class TimeUtilTest { + @Before + public void initLogging() { + System.setProperty("csp.sentinel.log.output.type", "console"); + } + + private void waitFor(int step, int seconds) throws InterruptedException { + for (int i = 0; i < seconds; i ++) { + Tuple2 qps = TimeUtil.instance().currentQps(TimeUtil.currentTimeMillis()); + RecordLog.info("step {} qps: reads={}, writes={}", step, qps.r1, qps.r2); + Thread.sleep(1000); + } + } + + @Test + public void test() throws InterruptedException { + final AtomicInteger delayTime = new AtomicInteger(50); + final AtomicBoolean shouldShutdown = new AtomicBoolean(); + for (int i = 0; i < 10; i ++) { + new Thread(new Runnable() { + + @Override + public void run() { + long last = 0; + while (true) { + if (shouldShutdown.get()) { + break; + } + long now = TimeUtil.currentTimeMillis(); + int delay = delayTime.get(); + if (delay < 1) { + if (last > now) { + System.err.println("wrong value"); + } + last = now; + continue; + } + try { + Thread.sleep(delay); + } catch (InterruptedException e) { + } + if (last > now) { + System.err.println("incorrect value"); + } + last = now; + } + } + }).start(); + } + Tuple2 qps; + waitFor(1, 4); + // initial state + assertEquals(TimeUtil.STATE.IDLE, TimeUtil.instance().getState()); + qps = TimeUtil.instance().currentQps(TimeUtil.currentTimeMillis()); + assertTrue(qps.r1 < 1000); + assertTrue(qps.r2 < 1000); + + // to RUNNING + delayTime.set(0); + // wait statistics to be stable + waitFor(2, 8); + qps = TimeUtil.instance().currentQps(TimeUtil.currentTimeMillis()); + assertEquals(TimeUtil.STATE.RUNNING, TimeUtil.instance().getState()); + assertTrue(qps.r1 > 1000); + assertTrue(qps.r2 <= 1000); + + // back + delayTime.set(100); + // wait statistics to be stable + waitFor(3, 8); + qps = TimeUtil.instance().currentQps(TimeUtil.currentTimeMillis()); + assertEquals(TimeUtil.STATE.IDLE, TimeUtil.instance().getState()); + assertTrue(qps.r1 < 1000); + assertTrue(qps.r2 < 1000); + shouldShutdown.set(true); + } + +}