GitLab官網(wǎng)在線倉庫SSH連接故障排查和經(jīng)驗(yàn)總結(jié)實(shí)例學(xué)習(xí)

GitLab在線倉庫服務(wù)是世界上最大的Git倉庫之一(github、gitlab和Bitbucket)。那么GitLab的工程師是如何定位和解決故障的呢？日前GitLab博客中介紹了這樣的一個(gè)實(shí)例，今天蟲蟲帶領(lǐng)大家一起學(xué)習(xí)。

緣起

運(yùn)維團(tuán)隊(duì)接收到客戶報(bào)告，他們在訪問Gitlab時(shí)候會(huì)間歇性地報(bào)告Git錯(cuò)誤，通常是來自CI工作段或類似的自動(dòng)化系統(tǒng)。錯(cuò)誤內(nèi)容為：

ssh_exchange_identification: connection closed by remote host

fatal: Could not read from remote repository

比較要命的是錯(cuò)誤信息是間歇性的隨機(jī)爆發(fā)，無法預(yù)測的，不能重現(xiàn)，也沒有明確指出截圖和日志來說明問題發(fā)生的各種現(xiàn)象和環(huán)境，當(dāng)然該錯(cuò)誤信息也太籠統(tǒng)沒有啥太大的意義。SSH客戶端報(bào)告該信息可能的原因：碎片化的客戶端或虛擬機(jī)，網(wǎng)絡(luò)防火墻行為，ISP做的手腳，當(dāng)然也有可能是GitLab應(yīng)用程序問題。GitLab在線倉庫每天要處理2600萬的Git-over-SSH的連接，大約平均每秒300個(gè)的鏈接，要從中發(fā)現(xiàn)少數(shù)幾個(gè)失敗，顯然是一件很有挑戰(zhàn)性的問題。

第一個(gè)線索

經(jīng)過初步分析后，運(yùn)維團(tuán)隊(duì)聯(lián)系了有問題的客戶，他說每天都會(huì)有多次出現(xiàn)這個(gè)問題，所以以此來作為出發(fā)點(diǎn)顯然很合適。客戶還提供了問題是對應(yīng)的公網(wǎng)IP地址，所以可以在的GitLab前端代理HAproxy節(jié)點(diǎn)抓包分析，定位到具體有問題的數(shù)據(jù)包信息。好消息是，客戶使用了alternate-ssh端口，這樣就可以只分析兩臺(tái)HAProxy服務(wù)器，將問題定位范圍進(jìn)一步由16減少到2。

抓包后，對篩選的IP大概6.5小時(shí)內(nèi)捕獲了大約500MB的數(shù)據(jù)包。在數(shù)據(jù)包中發(fā)現(xiàn)了一些短連接：建立了TCP連接，客戶端發(fā)送了一個(gè)版本字符串標(biāo)識(shí)符，然后HAProxy立即用正確的TCP FIN序列刪除連接。這是第一個(gè)很好的線索，它顯示，是由于GitLab服務(wù)器端主動(dòng)刪除鏈接的，所以問題的來源還是服務(wù)器端。

經(jīng)驗(yàn)一：Wireshark統(tǒng)計(jì)菜單有很多有用的工具，如果沒有真正實(shí)踐過都不會(huì)注意到。

比如"會(huì)話"會(huì)顯示捕獲中每個(gè)TCP連接的時(shí)間、數(shù)據(jù)包和字節(jié)大小，用他們進(jìn)行篩選。應(yīng)該在開始時(shí)使用它，而不是手動(dòng)拖動(dòng)捕獲。比如，該實(shí)例中需要尋找具有小數(shù)據(jù)包數(shù)量的連接，用會(huì)話視圖很容易顯示出來。然后，可以使用此功能查找其他實(shí)例，并驗(yàn)證第一個(gè)實(shí)例不是個(gè)一個(gè)個(gè)例。

日志分析

那么是什么導(dǎo)致HAProxy主動(dòng)刪除客戶端的連接的原因是啥？二期似乎不是任意做的，應(yīng)該有更深層次的原因。除了抓包日志，HAProxy日志是下一個(gè)要檢查的地方。GitLab在GCP BigQuery中存儲(chǔ)，并可以通過他們?yōu)g覽分析日志。首先，能夠根據(jù)時(shí)間和TCP端口識(shí)別數(shù)據(jù)包捕獲中的一個(gè)事件的日志條目，這是一個(gè)重大突破。該條目中最有趣的細(xì)節(jié)是t_state(終止?fàn)顟B(tài))屬性，即SD。HAProxy文檔顯示：

S：服務(wù)器中止，或者服務(wù)器明確拒絕它

D：會(huì)話處于DATA階段。

D很清楚，已正確建立TCP連接，并且正在發(fā)送數(shù)據(jù)，這與數(shù)據(jù)包捕獲證據(jù)相匹配。S表示HAProxy從后端收到RST或ICMP失敗消息。至于是哪種情況發(fā)生或可能的原因沒有直接的頭緒。可能是從網(wǎng)絡(luò)問題(例如故障或堵塞)直到應(yīng)用程序級(jí)問題的很多原因。使用BigQuery通過Git后端進(jìn)行聚合，很明顯它并不是特定于任何VM。

事實(shí)證明，帶有SD的日志并不是該問題所獨(dú)有的。在alternate-ssh端口上，會(huì)對HTTPS進(jìn)行大量掃描，會(huì)導(dǎo)致在SSH服務(wù)器看到TLS ClientHello消息時(shí)遇到SSH問候語時(shí)會(huì)記錄SD。

在捕獲HAProxy和Git服務(wù)器之間的一些流量并再次通過使用Wireshark統(tǒng)計(jì)工具時(shí)，很明顯Git服務(wù)器上的SSHD在TCP三次握手后立即拆除了與TCP FIN-ACK的連接。 HAProxy仍然沒有發(fā)送第一個(gè)數(shù)據(jù)包，但是即將發(fā)送狀態(tài)，當(dāng)它很快要發(fā)送時(shí)，Git服務(wù)器以TCP RST響應(yīng)。因此有理由HAProxy使用SD記錄連接失敗。SSH正在關(guān)閉連接，顯然就已經(jīng)關(guān)閉了。RST只是SSH服務(wù)器在FIN-ACK之后接收數(shù)據(jù)包，并不代表什么。

一張統(tǒng)計(jì)圖

在觀察和分析BigQuery中的SD日志時(shí)，很明顯在時(shí)間維度上有相當(dāng)多的聚類，在每分鐘頂部后的前10秒內(nèi)出現(xiàn)峰值，在開始約5-6秒后達(dá)到峰值：

連接錯(cuò)誤，按秒分組

上圖是根據(jù)幾個(gè)小時(shí)整理的數(shù)據(jù)創(chuàng)建的，因此實(shí)際的事實(shí)表明在幾分鐘和幾小時(shí)內(nèi)是一致的，甚至可能在一天的特定時(shí)間更糟。更有趣的是，平均峰值是基本負(fù)載的3倍，所以這意味著我們有擴(kuò)展問題，并且簡單地為虛擬機(jī)配置"更多資源"以滿足峰值負(fù)載可能會(huì)非常昂貴。也表明GitLab正在達(dá)到一些硬性限制，這是潛在系統(tǒng)性問題的第一個(gè)線索。

Cron或類似的調(diào)度系統(tǒng)通常只能細(xì)分到分鐘級(jí)別。所以很多任務(wù)都在分鐘或小時(shí)的開始或其整數(shù)運(yùn)行。如果他們在從GitLab進(jìn)行g(shù)it獲取之前花費(fèi)幾秒鐘做準(zhǔn)備工作，這將解釋連接模式在數(shù)秒鐘到一分鐘內(nèi)增加，從而導(dǎo)致這些時(shí)間點(diǎn)的錯(cuò)誤累積。

經(jīng)驗(yàn)二：顯然很多人都正確地設(shè)置了時(shí)間同步(通過NTP或其他方式)。

如果他們沒有，這個(gè)問題就不會(huì)那么清楚了。那么是什么可能導(dǎo)致SSH丟棄連接的呢？

接近問題實(shí)質(zhì)

通過查看SSHD的文檔，發(fā)現(xiàn)MaxStartups參數(shù)，它可以控制處于預(yù)認(rèn)證狀態(tài)的最大連接數(shù)。在波峰的時(shí)刻，互聯(lián)網(wǎng)預(yù)定的任務(wù)的沖擊下，似乎超出了連接限制似乎也是合理的。MaxStartups實(shí)際上有三個(gè)數(shù)字：低watermark(開始丟棄連接的數(shù)量)，低watermark以上任何連接的(隨機(jī))丟棄連接的百分比，以及超過所有新連接的絕對最大值。默認(rèn)值為10:30和100，GitLab的設(shè)置為100:30:200，顯然我們過去曾經(jīng)增加過連接設(shè)置，也需要再加大配置。

問題是，Gitlab服務(wù)器上openssh版本是7.2，并且在該版本中查看MaxStartups設(shè)置的唯一方法需要打開調(diào)試級(jí)別日志記錄。這是可能對導(dǎo)致數(shù)據(jù)泄漏，所以只能在一臺(tái)服務(wù)器上測試打開。打開調(diào)試日志后，在幾分鐘內(nèi)，明顯MaxStartups設(shè)置就被超出了，因此連接被提前放棄。

事實(shí)證明，OpenSSH 7.6(Ubuntu 18.04附帶的版本)有更好的MaxStartups日志記錄，只需要Verbose日志記錄就可以獲得該信息。雖然不很理想，但總比Debug級(jí)別更好。

經(jīng)驗(yàn)三：在默認(rèn)日志級(jí)別記錄有用信息很有意義，出于任何原因服務(wù)器主動(dòng)丟棄連接絕對是運(yùn)維的鍋。

問題的原因找到了，那么如何解決呢？我們可以調(diào)大MaxStartups配置，但是這么做的代價(jià)是多少呢？這會(huì)增加一小部分內(nèi)存，但它會(huì)有其他影響？不能光靠推測，所以需要實(shí)際測試。首先是將值MaxStartups提高到50%，調(diào)整為150:30:300。該配置帶來很大積極作用，并且沒有明顯的負(fù)面影響(例如CPU負(fù)載，負(fù)載等)：

看上圖，注意到0??1:15之后錯(cuò)誤數(shù)大幅減少。明顯已經(jīng)消除了很大一部分錯(cuò)誤，盡管仍然存在非常微不足道的數(shù)量。圖形顯示聚集在一致的高峰的時(shí)間，每隔30分鐘，15分鐘和10分鐘。重要的時(shí)刻是最高峰，這也跟實(shí)際使用相吻合，很多人會(huì)安排他們的任務(wù)在每小時(shí)0分鐘的時(shí)間內(nèi)每小時(shí)運(yùn)行一次。這一發(fā)現(xiàn)更加證實(shí)事實(shí)，由于預(yù)定的工作導(dǎo)致連接峰值，連接錯(cuò)誤是由于最大連接數(shù)的限制。

沒有明顯的負(fù)面影響，SSH服務(wù)器上的CPU使用率保持不變，沒有任何明顯的負(fù)載增加，通過簡單配置就釋放了之前被刪除的很多連接。

限速

但是并不能一味的簡單調(diào)高M(jìn)axStartups配置，雖然通過配置增加50%的數(shù)值，但繼續(xù)增加這一數(shù)字也不行，還有其他可以做優(yōu)化的事情。

HAProxy為其前端偵聽器提供了一個(gè)很好的"速率限制會(huì)話"選項(xiàng)。配置后，它會(huì)限制前端將傳遞給后端的每秒新TCP連接數(shù)，并在TCP套接字上保留其他連接。如果傳入速率超過限制(每毫秒測量)，則新連接將被延遲。TCP客戶端(在這種情況下為SSH)只是在建立TCP連接之前看到延遲，這樣不會(huì)有太大影響，只要總體從未超過限制太長時(shí)間。由于Gitlab有27個(gè)SSH后端和18個(gè)HAproxy前端(16個(gè)主要，兩個(gè)alt-ssh)，并且前端之間沒有做過速率限制優(yōu)化，調(diào)整比較麻煩，必須考慮新的SSH會(huì)話需要多長時(shí)間通過身份驗(yàn)證：假設(shè)MaxStartups為150，如果auth階段需要兩秒鐘，每秒只能向每個(gè)后端發(fā)送75個(gè)新會(huì)話。計(jì)算速率限制需要四個(gè)數(shù)量：兩種服務(wù)器類型的數(shù)量，MaxStartups的值和T，這是SSH會(huì)話進(jìn)行身份驗(yàn)證所需的時(shí)間。T值很關(guān)鍵，但只能估計(jì)。最后配置為每個(gè)前端的速率限制大約為112.5，并向下舍入到110。

調(diào)整部署后，一切都OK了？錯(cuò)誤連接數(shù)應(yīng)該為零，但是，實(shí)際上，這個(gè)配置并沒有對錯(cuò)誤率有明顯影響。陷入深深的沉思，一定錯(cuò)過了了啥！

所以回到日志(最終是HAProxy指標(biāo))，確保能夠驗(yàn)證速率限制是否生效了，并且歷史顯示這個(gè)數(shù)字已經(jīng)更高，所以成功地約束了發(fā)送連接的速率。但顯然這個(gè)比率仍然太高，它還不足以接近正確的數(shù)字，以產(chǎn)生可衡量的影響。

查看后端(由HAproxy記錄)顯示了一個(gè)奇怪的現(xiàn)象：在一小時(shí)的峰值，后端連接并非均勻分布在所有SSH服務(wù)器上。在所選的時(shí)間內(nèi)，它在給定的秒內(nèi)從30變化到121，這意味著負(fù)載平衡不是很平衡。查看配置使用的"balance source"，因此給定的客戶端IP地址始終會(huì)連接到同一后端。如果需要會(huì)話粘性，這是很好的策略，但是對SSH，沒有這樣的需求。因此嘗試將其更改為"leastconn"，使用最少數(shù)量的當(dāng)前連接將新的傳入連接分發(fā)到后端。使用新策略后SSH(Git)CPU使用率的結(jié)果：

顯然，該策略很有效果。兩條低使用率的線條，顯示的是Canary服務(wù)器，可以忽略不計(jì)，但在策略更改之前由于源IP分布不均勻服務(wù)器之間負(fù)載差異是2：1(30%到60%)，很明顯我們的一些后端比其他后端更加繁忙。。

經(jīng)驗(yàn)四：當(dāng)選擇特定的非默認(rèn)設(shè)置時(shí)，需要注釋或鏈接到文檔/問題，為什么，后來者會(huì)感謝你。

啟用leastconn策略后錯(cuò)誤率也明顯降低了。繼續(xù)，試驗(yàn)限速配置，將速率限制降低到100，這進(jìn)一步降低了錯(cuò)誤率，表明可能對T的初始估計(jì)是錯(cuò)誤的。但如果是這樣限制會(huì)導(dǎo)致速率限制太高，甚至100/s感覺非常低，我們不想進(jìn)一步放棄它。隨著速率限制盡可能低，而且最小化不足，嘗試增加MaxStartups：首先是為200，有效，然后到250，錯(cuò)誤幾乎消失了，而沒有任何負(fù)面結(jié)果。

經(jīng)驗(yàn)四：盡管很違常理，但是MaxStartups似乎對性能影響很小，即使它的提升遠(yuǎn)遠(yuǎn)高于默認(rèn)值時(shí)。

如果有必要，這可能是未來可以提供的一個(gè)更大水平。如果它提高到成千上萬或數(shù)萬，可能會(huì)注意到其影響問題。

這說明對T的估計(jì)，建立和驗(yàn)證SSH會(huì)話的時(shí)間是什么？通過測試知道200對MaxStartups來說還不夠，250就足夠了，可以計(jì)算出T可能在2.7到3.4秒之間。。

善后

事后通過查看日志，經(jīng)過一番思考后，發(fā)現(xiàn)可以識(shí)別出一個(gè)特定的故障模式：t_state為SD，b_read(客戶端讀取的字節(jié)數(shù))為0。如上所述，GitLab每天處理大約26-28萬個(gè)SSH連接。令人不快的是，在最嚴(yán)重情況下，大約有1.5%的連接被嚴(yán)重丟棄。顯然，問題比開始時(shí)意識(shí)到的要大，之前無法確定這一點(diǎn)(當(dāng)發(fā)現(xiàn)t_state ="SD"表示問題時(shí)，沒有想到這一點(diǎn))。

經(jīng)驗(yàn)六：盡早測量錯(cuò)誤占比

如果能意識(shí)到問題的嚴(yán)重程度，可能會(huì)更早地優(yōu)先考慮該問題，盡管它仍然依賴于了解識(shí)別特征。從好的方面來看，在遇到MaxStartups和速率限制后，錯(cuò)誤率降至0.001%，即每天幾千。這比較好，但仍然高于期望。在解決其他一些操作問題之后，希望能夠正式部署最小的變更，并且可以完全消除了錯(cuò)誤。

進(jìn)一步的工作

顯然SSH身份驗(yàn)證階段仍需要很長時(shí)間，可能長達(dá)3.4秒。GitLab可以使用AuthorizedKeysCommand直接在數(shù)據(jù)庫中查找SSH密鑰。當(dāng)擁有大量用戶時(shí)，這對于快速操作至關(guān)重要，否則SSHD必須按順序讀取非常大的authorized_keys文件以查找用戶的公鑰，并且這不能很好實(shí)現(xiàn)橫向擴(kuò)展。目前使用一些調(diào)用內(nèi)部HTTP API的ruby實(shí)現(xiàn)查找。工程研究員Stan Hu和GitLab知識(shí)的常駐來源，確定Git/ SH服務(wù)器上的實(shí)例正在經(jīng)歷大量排隊(duì)。這可能是~3秒預(yù)認(rèn)證階段的重要貢獻(xiàn)者，因此需要進(jìn)一步研究解決。

當(dāng)看到表明問題正在發(fā)生的HAProxy日志時(shí)，還需要發(fā)出警報(bào)。后續(xù)可能還需要進(jìn)一步增加MaxStartup配置，或者如果資源限制了，則添加更多Git/SSH節(jié)點(diǎn)。

總結(jié)

本文通過GitLab線上服務(wù)的一個(gè)實(shí)例分析，顯示了線上問題排查的全過程，通過抓包、日志定位，參數(shù)配置調(diào)整測試和問題總結(jié)等過程全面展示了從問題發(fā)現(xiàn)、定位到解決的全過程，并且在該過程中進(jìn)行經(jīng)驗(yàn)總結(jié)。總之該問題不是特例，該問題解決方法、步驟和思路更是可以學(xué)習(xí)和推廣的好案例。

總結(jié)

以上是生活随笔為你收集整理的coreelec ssh访问被拒绝_GitLab官网在线仓库SSH连接故障排查和经验总结实例的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。