18.750 istek/sn: kesin, tekrarlanmış ve üç kat yanlış

Ölçüm üç tekrar koştu, üçü de birbirine yakın çıktı, medyan 18.750’ydi. Aynı adayı aynı dört çekirdekte dakikalar önce ölçen başka bir faz 55.715 demişti. İkisi de kendi içinde tutarlıydı ve ikisi de aynı koşunun parçasıydı.

Nereden çıktı

İş yerinde, her istekte OAuth2 token’ı doğrulayıp saniyede on binlerce okuma ve yazma karşılayacak bir servis için Go önerdim. Ekip haklı bir soru sordu: ne kadar kazanıyoruz? Ölçmeyi seven biri olduğum için bu tam istediğim türden bir soruydu ve aynı API’yi Go, PHP-FPM ve FrankenPHP worker ile üç kez yazıp bir tezgâh kurdum.

Tezgâh şunu yapıyordu: karma trafiği (yarısı okuma, yarısı yazma) sabit bir hızda bas, hız hedefi tutuyorsa ve p99 on milisaniyenin altındaysa geç, değilse kal. Sonra hızı ikiye katla, başarısız olunca aradaki aralığı ikili aramayla daral. Kapasite, servis seviyesini karşılayan en yüksek hız olsun. Bu, benim de başkalarının da yazacağı türden makul bir düzenek.

Çıkan sayı sonuç gibi okunuyordu

Dört çekirdekli Go için tezgâh 18.750 istek/sn verdi. “Üç tekrarın medyanı” etiketiyle. Bir tabloya yazsanız kimse itiraz etmez.

Aynı koşunun ayar fazı vardı: her adayı her çekirdek bütçesinde farklı havuz boyutlarıyla tam gaz koşturup en iyisini seçiyordu. O faz, aynı Go servisini aynı dört çekirdekte 55.715 ölçmüştü. Üç kat fark.

İkisinden biri yanlıştı ve hangisi olduğunu bana hiçbir şey söylemiyordu. Merdivenin üç tekrarı birbirine yakındı; ayar fazının iki tekrarı da birbirine yakındı. Her iki ölçüm de kendi içinde tutarlıydı. Tutarlılık doğruluk değil.

Veriye bakınca daha kötüsü çıktı: merdivenin tekrarları 1.250 ile 48.000 arasında geziyordu. Medyan 18.750’ydi çünkü ortadaki tekrar oraya düşmüştü.

Birinci teşhis: doğruydu ve yetmedi

Bozuk pencereleri tek tek okudum. Bir hücrenin ilk adımı, saniyede 3.000 istekte, yazma p99’unu 10,6 ms göstermişti — eşiğin altı onda biri kadar üstünde. Okuma p99’u aynı pencerede 3,3 ms’ydi. Yani darbe yalnız yazma tarafına gelmişti.

Sebep tezgâhımdaydı: her adımdan önce tabloyu tohumlanmış hâline döndürüyor ve CHECKPOINT alıyordum. Checkpoint’in geri yazımı ölçüm penceresine taşınca yazmalar takılıyordu. Üstel arama da bunu bir hükme çeviriyordu: 48.000 taşıyacak bir hücrenin ilk adımı başarısız yazılınca, aramanın bisect edecek geçmiş bir başarısı olmuyor, aşağı dönüyor ve hücrenin geri kalanını Go’nun 1.250 istek/sn taşıdığını doğrulamakla geçiriyordu.

Reset’ten sonra bekleme koydum. Başarısız bir pencereyi, arama ona göre davranmadan önce ikinci kez ölçtürdüm. Yeniden koşturdum.

İkinci deneme daha kötü çıktı

Sonuç şuydu:

Hücre	tekrar 1	tekrar 2	tekrar 3
Go, 1 çekirdek	1.250	6.500	3.500
PHP-FPM, 1 çekirdek	1.750	2.750	750

Aynı hücrenin tekrarları beş kat ayrışıyordu. Ve bu sefer hiçbir pencere bozuk değildi: istekler cevaplanıyor, hata dönmüyor, CPU sabit bir yerde duruyordu. Düzelttiğim şey gerçek bir sorundu ama asıl sorun o değildi.

Dönüm: oha iki gecikme raporluyor

PHP-FPM, tek çekirdek, saniyede 3.000 istek. Doksan bin isteğin hepsi cevaplanmış, hedef hız birebir tutmuş, medyan 1,44 ms, CPU tek çekirdeğin 0,76’sı — doygun bile değil. Ve p99: 3.718 ms.

Yük üretecinin çıktısında iki ayrı gecikme sütunu vardı:

	p50	p75	p99	en yavaş
time to first byte	1,42 ms	47 ms	191 ms	267 ms
latency-corrected	1,44 ms	1.539 ms	3.718 ms	3.819 ms

Sunucu 191 ms’de cevaplamıştı. Kalan 3,5 saniye, isteğin gönderilmeyi bekleme süresiydi.

Mekanizma: doğru şeyi yapmak sınırı uçuruma çevirir

--latency-correction, isteği gönderildiği andan değil gönderilmesi gerektiği andan itibaren sayar. Bu doğru şeydir: yük üretecinin sistemle birlikte nazikçe yavaşlayıp “geçti” demesini engelleyen tek mekanizma budur. Coordinated omission literatürü bunu uzun uzun anlatır ve orada biter.

Anlatmadığı şey, düzeltmeyi uyguladıktan sonra ne olduğu. Cevaplar üretecin bağlantılarını dolduracak kadar yavaşlayınca takvim kayıyor ve sonraki her istek kaymayı devralıyor. Sonuç: bir hız ya rahatça karşılanıyor ya da felaket biçimde ıskalanıyor, arada neredeyse hiçbir şey yok. Sınır bir eğim değil, uçurum.

Ve uçurum tekrarlar arasında yer değiştiriyor.

İşte aramanın ölçemediği şey bu. Üstel arama ile ikili bölme, geçme/kalmanın hızda monoton ve tek tek sorgulanabilecek kadar kararlı olduğunu varsayar. İkisi de doğru değildi. Her tekrar farklı bir soru dizisi soruyor, hareketli bir sınırın üzerinde farklı bir yol yürüyor ve yolun bittiği yeri rapor ediyordu.

Çözüm ve bir yalan daha

Aramayı attım. Yerine hücre başına yedi sabit hız koydum — her tekrarda aynı yedisi — ve bir hız, tekrarların çoğunluğu onu taşıdıysa taşınmış sayıldı. Yönlendirilecek bir şey yok; bozuk bir pencere bir tekrarda bir noktaya mal oluyor, oy onu yutuyor.

Sonra ana makine yalan söyledi. Tavan fazını koştururken sayılar yine saçmaydı: dört çekirdekli Go 17.490 istek/sn. Süreçlere baktım — macOS’ta otuz kadar headless Chromium süreci toplam %1.019 CPU kullanıyordu. On iki çekirdeğin onundan fazlası. Docker VM’ine %94 kalmıştı.

Bu benim tezgâhımın kusuru değildi ama tezgâhımın görmesi gereken bir şeydi. İki şey ekledim: her tekrardan önce, uygulama kodu çalıştırmayan bir nginx’i adayın kendi çekirdeklerine koyup beklenen hızın %115’ini isteyen bir yoklama — altında kalan tekrar adayı değil üreteci ölçmüştür, elenir — ve her tekrarın yanına macOS’un o anki yükünün kaydı.

Sonuç

Sakin bir makinede, hücre başına beş tekrar: 45 tekrarın 45’i yoklamadan geçti. Go’nun dört çekirdekteki beş tekrarı 55.836 ile 57.321 arasına düştü, medyan 56.571. Ve on iki saat önce, farklı bir bağlantı sayısıyla, kapalı çevrimde ölçen ayar fazı 55.715 demişti.

İki bağımsız ölçüm birkaç yüzde içinde örtüştü. Sayının doğru olduğunu bana söyleyen şey buydu — istatistik değil, ikinci bir yöntem.

Ne öğrendim

Bariz çöp üreten bir ölçüm iyi haberdir: bakarsınız. Tehlikeli olan, üç ondalık basamakla ve “üç tekrarın medyanı” etiketiyle yanlış olandır, çünkü o sayı bir sunuma girer ve kimse itiraz etmez.

Tekil bir ölçüm kendi kendini denetleyemez. Tekrar sayısını artırmak yetmez — benim üç tekrarım da tutarlıydı. Daha iyi bir istatistik de yetmez; medyan tam da ortadaki yanlış tekrarı seçmişti.

Yetecek olan, aynı büyüklüğü başka yoldan ölçen ikinci bir faz. Benimki kazara vardı: havuz boyutunu seçmek için kapalı çevrimde koşan ayar fazı, açık çevrimdeki merdivenle üç kat çelişti ve alarmı o çaldı. Bugün bilerek tutuyorum.

Kendi düzeneğinize eklemek için üç somut şey:

• Aynı büyüklüğü farklı çevrimde ölçen ikinci bir faz (biri açık, biri kapalı) ve ikisi ayrıştığında koşuyu geçersiz sayan bir kural.
• Her tekrardan önce bir yoklama: ölçtüğünüz şeyin gerçekten aday olduğunu kanıtlayan, uygulama kodu çalıştırmayan bir hedef.
• Tekrarın yanında ortamın kaydı. Sayının yanlış olduğunu sonradan anlarsanız nedenini de bilirsiniz.

Ölçümün kendisi, çıkan sayılar ve elenen üç denemenin ham verisi araştırma defterinde; teşhisin tamamı deponun EXCLUDED.md dosyasında. Sildiğim sayıları da orada tutuyorum — yanlış bir ölçümün nasıl yanlış olduğu, doğru olanın kendisinden çok şey öğretiyor.