Skip to content

Commit

Permalink
Improve performance of TimeUtil adaptively in different load conditio…
Browse files Browse the repository at this point in the history 
…ns (alibaba#1746)

To achieve this by making 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 anymore.

Signed-off-by: Jason Joo <[email protected]>
  • Loading branch information
@jasonjoo2010
jasonjoo2010 authored and taz committed Aug 16, 2021
1 parent 07cacdd commit 7fae4e1
Show file tree
Hide file tree
Showing 2 changed files with 300 additions and 16 deletions.
205 changes: 189 additions & 16 deletions sentinel-core/src/main/java/com/alibaba/csp/sentinel/util/TimeUtil.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,38 +15,211 @@
*/
package com.alibaba.csp.sentinel.util;

import java.util.List;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.LongAdder;

import com.alibaba.csp.sentinel.log.RecordLog;
import com.alibaba.csp.sentinel.slots.statistic.base.LeapArray;
import com.alibaba.csp.sentinel.slots.statistic.base.WindowWrap;
import com.alibaba.csp.sentinel.util.function.Tuple2;

/**
* Provides millisecond-level time of OS.
* <p>Provides millisecond-level time of OS.</p>
* <p>
* 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).
* <pre>
* * In idle conditions it just acts as System.currentTimeMillis();
* * In busy conditions (significantly more than 1_000/s) it keeps loop to reduce costs.
* </pre>
* For detail design and proposals please goto
* <a href="https://github.com/alibaba/Sentinel/issues/1702#issuecomment-692151160">https://github.com/alibaba/Sentinel/issues/1702</a>
*
* @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 final LongAdder writes = new LongAdder();
private final LongAdder reads = new LongAdder();

public LongAdder getWrites() {
return writes;
}

public LongAdder getReads() {
return reads;
}
}

private static TimeUtil INSTANCE;

private volatile long currentTimeMillis;
private volatile STATE state = STATE.IDLE;

private LeapArray<Statistic> statistics;

private static volatile long currentTimeMillis;
/**
* 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<TimeUtil.Statistic>(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<Statistic> resetWindowTo(WindowWrap<Statistic> 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) {
// Mechanism optimized since 1.8.2
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.debug("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<Long, Long> currentQps(long now) {
List<WindowWrap<Statistic>> list = this.statistics.listAll();
long reads = 0;
long writes = 0;
int cnt = 0;
for (WindowWrap<Statistic> windowWrap : list) {
if (windowWrap.isTimeInWindow(now)) {
continue;
}
cnt++;
reads += windowWrap.value().getReads().longValue();
writes += windowWrap.value().getWrites().longValue();
}
if (cnt < 1) {
return new Tuple2<Long, Long>(0L, 0L);
}
return new Tuple2<Long, Long>(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<Long, Long> 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();
}
}
111 changes: 111 additions & 0 deletions sentinel-core/src/test/java/com/alibaba/csp/sentinel/util/TimeUtilTest.java
View file
Original file line number Diff line number Diff line change
@@ -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<Long, Long> 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<Long, Long> 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);
}

}

0 comments on commit 7fae4e1

Please sign in to comment.