亚洲视频免费观看视频,91九色91蝌蚪91窝成人,中国操逼网站,久操久操,免费三级黄色,天天爱天天干天天爽,欧美V日韩V国产V,天天色五月

點(diǎn)擊上方“服務(wù)端思維”，選擇“設(shè)為星標(biāo)”

回復(fù)”669“獲取獨(dú)家整理的精選資料集

回復(fù)”加群“加入全國(guó)服務(wù)端高端社群「后端圈」

作者 |?枕邊書_5277

出品?|?http://3kdtp.cn/9JiXJ

| 問(wèn)題

請(qǐng)求被限流

之前的文章提到過(guò)我們服務(wù)使用Hystrix進(jìn)行服務(wù)限流，使用的是信號(hào)量方式，并根據(jù)接口的響應(yīng)時(shí)間和服務(wù)的峰值QPS設(shè)置了限流的配額。

限流配額的計(jì)算方式為：

我們接口單機(jī)單個(gè)接口的峰值QPS為1000，平均影響時(shí)長(zhǎng)15ms，我們認(rèn)為Hystrix的信號(hào)量是并發(fā)量，那么一個(gè)信號(hào)量在一秒內(nèi)能允許1000ms/15ms~66個(gè)請(qǐng)求通過(guò)，那么服務(wù)1000QPS配置15個(gè)信號(hào)量就足夠了。

當(dāng)然這是在忽略上下文切換和GC時(shí)間的情況下，考慮上這些因素，每個(gè)并發(fā)量每秒能服務(wù)的時(shí)長(zhǎng)約為900ms，用同樣的公式計(jì)算所需要的信號(hào)量是17，為了應(yīng)付突發(fā)流量，我將這個(gè)值設(shè)置為了30。

本以為這樣就高枕無(wú)憂了，沒(méi)想到看錯(cuò)誤日志中偶然發(fā)現(xiàn)了有報(bào)錯(cuò)：

HystrixRuntimeException?occurred!?,?failureType:REJECTED_SEMAPHORE_EXECUTION,?message:apiHystrixKey?could?not?acquire?a?semaphore?for?execution?and?fallback?failed.

我把信號(hào)量配置提高到了50，沒(méi)想到還是沒(méi)看到問(wèn)題有明顯好轉(zhuǎn)，這就比較詭異了。

| 解決

排查步驟

首先我列了一下排查的步驟，也整理一下出現(xiàn)這種問(wèn)題的可能。

看正常請(qǐng)求的平均耗時(shí)，排除真實(shí)block的可能。接口平均耗時(shí)17ms，QPS為1000，如果代碼都被block在某處，接口耗時(shí)一定會(huì)突增。
查看一下hystrix代碼看是否可能有情況導(dǎo)致信號(hào)量未釋放。簡(jiǎn)單掃了一遍hystrix相關(guān)代碼，信號(hào)量的釋放在請(qǐng)求結(jié)束的callback里，如果有泄漏，一定會(huì)導(dǎo)致可用信號(hào)量越來(lái)越少，最終為0。
寫一個(gè)小demo，壓測(cè)看是否能復(fù)現(xiàn)。在demo里運(yùn)行，問(wèn)題只在剛啟動(dòng)服務(wù)未初始化完成時(shí)復(fù)現(xiàn)，后續(xù)就平穩(wěn)了。

Jdk的Bug ？

從整體上看不出來(lái)，就只好從微觀時(shí)間點(diǎn)上看了，可這個(gè)問(wèn)題出現(xiàn)是一瞬間的事，jstack也無(wú)能為力，雖然jmc倒是合適，但它部署有點(diǎn)費(fèi)勁，而且還會(huì)在觀察的時(shí)候影響到服務(wù)，于是優(yōu)先從歷史時(shí)間點(diǎn)上排查。

從錯(cuò)誤日志里找了一個(gè)服務(wù)拒絕數(shù)較多的時(shí)間點(diǎn)，再觀察服務(wù)當(dāng)時(shí)的狀態(tài)。錯(cuò)誤日志上除了一些請(qǐng)求被拒絕的報(bào)錯(cuò)外就沒(méi)有其他的了，但我在gclog里發(fā)現(xiàn)了奇怪的日志。

2020-03-17T13:01:26.281+0800:?89732.109:?Application?time:?2.1373599?seconds
2020-03-17T13:01:26.308+0800:?89732.136:?Total?time?for?which?application?threads?were?stopped:?0.0273134?seconds,?Stopping?threads?took:?0.0008935?seconds
2020-03-17T13:01:26.310+0800:?89732.137:?Application?time:?0.0016111?seconds
2020-03-17T13:01:26.336+0800:?89732.163:?[GC?(Allocation?Failure)?2020-03-17T13:01:26.336+0800:?89732.164:?[ParNew
Desired?survivor?size?429490176?bytes,?new?threshold?4?(max?4)
-?age?1:?107170544?bytes,?107170544?total
-?age?2:?38341720?bytes,?145512264?total
-?age?3:?6135856?bytes,?151648120?total
-?age?4:?152?bytes,?151648272?total
:?6920116K->214972K(7549760K),?0.0739801?secs]?9292943K->2593702K(11744064K),?0.0756263?secs]?[Times:?user=0.65?sys=0.23,?real=0.08?secs]
2020-03-17T13:01:26.412+0800:?89732.239:?Total?time?for?which?application?threads?were?stopped:?0.1018416?seconds,?Stopping?threads?took:?0.0005597?seconds
2020-03-17T13:01:26.412+0800:?89732.239:?Application?time:?0.0001873?seconds
2020-03-17T13:01:26.438+0800:?89732.265:?[GC?(GCLocker?Initiated?GC)?2020-03-17T13:01:26.438+0800:?89732.265:?[ParNew
Desired?survivor?size?429490176?bytes,?new?threshold?4?(max?4)
-?age?1:?77800?bytes,?77800?total
-?age?2:?107021848?bytes,?107099648?total
-?age?3:?38341720?bytes,?145441368?total
-?age?4:?6135784?bytes,?151577152?total
:?217683K->215658K(7549760K),?0.0548512?secs]?2596413K->2594388K(11744064K),?0.0561721?secs]?[Times:?user=0.49?sys=0.18,?real=0.05?secs]
2020-03-17T13:01:26.495+0800:?89732.322:?Total?time?for?which?application?threads?were?stopped:?0.0824542?seconds,?Stopping?threads?took:?0.0005238?seconds

我看到連續(xù)發(fā)生了兩次YGC，它們之間的間隔才0.0001873s，可以認(rèn)為是進(jìn)行了一次很長(zhǎng)時(shí)間的GC，總耗時(shí)達(dá)到了160ms。再仔細(xì)觀察第二次GC時(shí)的內(nèi)存分布，可以看到它作為一次ParNew GC，發(fā)生時(shí)eden區(qū)的內(nèi)存才使用了200M，這就不符合常理了。

再看GC發(fā)生的原因，日志里標(biāo)識(shí)的是GCLocker Initiated GC。在使用 JNI操作字符串或數(shù)組時(shí)，為了防止GC導(dǎo)致數(shù)組指針發(fā)生偏移，JVM實(shí)現(xiàn)了GCLocker，它會(huì)在發(fā)生GC的時(shí)候阻止程序進(jìn)入臨界區(qū)，并在最后一個(gè)臨界區(qū)內(nèi)的線程退出時(shí)，發(fā)生一次GCLocker GC。

至于這次的GC，是JDK的一個(gè)Bug，JDK-8048556，具體原因可以看這篇博客：一次不必要的GCLocker-initiated young GC。

而我們的Java版本低于修復(fù)版本，出現(xiàn)這種問(wèn)題實(shí)屬正常，可是，這個(gè)問(wèn)題就歸究于jdk的bug嗎？升級(jí)了jdk版本就一定會(huì)好嗎？

“平均”的陷阱

重新來(lái)計(jì)算一下，即使JVM每秒都有160ms在進(jìn)行GC，可系統(tǒng)有服務(wù)時(shí)間也還有840ms，使用上文中的公式，信號(hào)量的還是完全足夠的。

一時(shí)想不明白，出去倒了杯水，走了走，忽然想到原來(lái)自己站錯(cuò)了角度。我一直用秒作為時(shí)間的基本單位，用一秒的平均狀態(tài)來(lái)代表系統(tǒng)的整體狀態(tài)，認(rèn)為一整秒內(nèi)如果沒(méi)有問(wèn)題，服務(wù)就不應(yīng)該會(huì)發(fā)生問(wèn)題，可是忽略了時(shí)間從來(lái)不是一秒一秒進(jìn)行的。

試想，如果平穩(wěn)運(yùn)行的服務(wù)，忽然發(fā)生了一次160ms的GC，那么這 160ms內(nèi)的請(qǐng)求會(huì)平均分配到剩余840ms內(nèi)嗎？并不會(huì)，它們會(huì)擠在第161ms一次發(fā)送過(guò)來(lái)，而我們?cè)O(shè)置的信號(hào)量限制會(huì)作出什么反應(yīng)呢？

????@Override
????public?boolean?tryAcquire()?{
????????int?currentCount?=?count.incrementAndGet();
????????if?(currentCount?>?numberOfPermits.get())?{
????????????count.decrementAndGet();
????????????return?false;
????????}?else?{
????????????return?true;
????????}
????}

上面是Hystrix源碼中獲取信號(hào)量的代碼，可以發(fā)現(xiàn)，代碼里沒(méi)有任何block，如果當(dāng)前使用的信號(hào)量大于配置值，就會(huì)直接拒絕。

這樣就說(shuō)得通了，如果進(jìn)行了160ms的GC，再加上請(qǐng)求處理的平均耗時(shí)是15ms，那系統(tǒng)就有可能在瞬間堆積1000q/s * 0.175s = 175的請(qǐng)求，如果信號(hào)量不足，請(qǐng)求就會(huì)被直接拒絕了。

也就是說(shuō)即使jdk的bug修復(fù)了，信號(hào)量限制最少還是要設(shè)置為95才不會(huì)拒絕請(qǐng)求。

| 限流配額的正確計(jì)算方式

概念

那么限流配額的正確計(jì)算方式是怎樣的呢？

在此之前我們要明確設(shè)置的限流配額都是并發(fā)量，它的單位是：個(gè)，這一點(diǎn)要區(qū)分于我們常用的服務(wù)壓力指標(biāo)QPS，因?yàn)镼PS是指一秒內(nèi)的請(qǐng)求數(shù)，它的單位是?個(gè)/S，由于單位不同，它們是不能直接比較的，需要并發(fā)量再除以一個(gè)時(shí)間單位才可以。

正確的公式應(yīng)當(dāng)是：并發(fā)量(個(gè))/單個(gè)請(qǐng)求耗時(shí)(s) > QPS(個(gè)/s)。

但由于Java GC的特性，我們不得不考慮GC期間請(qǐng)求堆積的可能，要處理這種情況，第一種是直接拒絕，像Hystrix的實(shí)現(xiàn)（有點(diǎn)坑），第二種是做一些緩沖。

信號(hào)量緩沖

其實(shí)信號(hào)量并不是無(wú)法做緩沖的，只是Hystrix 內(nèi)的”信號(hào)量”是自己實(shí)現(xiàn)的，比較low。

比較”正統(tǒng)”的方式是使用jdk里的java.util.concurrent.Semaphore，它獲取信號(hào)量有兩種方式，第一種是tryAcquire()，這類似于Hystrix的實(shí)現(xiàn)，是不會(huì)block的，如果當(dāng)前信號(hào)量被占用或不足，會(huì)返回false。第二種是使用acquire()方法，它沒(méi)有返回值，意思是方法只有在拿到信號(hào)量時(shí)才會(huì)返回，而這個(gè)時(shí)間是不確定的。

我猜想這可能也是Hystrix不采用這種方式的原因，畢竟如果使用FairSync會(huì)有很多拿到信號(hào)量發(fā)現(xiàn)接口超時(shí)再拋棄的行為，而使用UnFairSync又會(huì)使接口的影響時(shí)長(zhǎng)無(wú)法確定。