2019獨角獸企業重金招聘Python工程師標準>>>

基于日志的統計分析按日志來源一般分為后端 cgi、app 日志和前端 js 掛碼日志，其中前端 js 掛碼由于與具體后端業務邏輯低耦合、異步加載等特性，使得其在網站統計分析領域應用廣泛。

今天就來看一個 nginx 日志收集過程中的 case。

最近在 review nginx 配置的時候，發現 nginx 每天會有 1% 的 errlog，由于公司的業務訪問量還算比較大的，算下來這 1% 也不是個小數目，有必要搞清楚這 1% 究竟怎么產生的。

1、錯誤日志樣式：

錯誤日志的樣式大致分為兩種，如下：

2014/07/03?00:06:51?[error]?30605#0:?*15901655967?client?sent?invalid?userid?cookie?"cookieuid1=05dvUVObOC+UGCrSG4gWAg==;?jobbest_cateid=38676;?isfirst=true;?showcountdown=true;?stopnotice=true;?_TCN=4FD2E673D11B18C5060BF413BB796EB5;?idooxx="05dz8VO0Lew1TT66I0MUAg==";?...2014/08/13?11:01:25?[error]?13702#0:?*19402474334?open()?"/opt/web/tracklog.ooxx.com.static/mooxx/m3/js/m.lazyload.js"?failed?(2:?No?such?file?or?directory),?client:?42.249.142.200,?server:?tracklog.ooxx.com,?...

前者在整個 errlog 中占比 99%，后者 1% 左右，前者就是今天要討論的主題：為什么 nginx 會報這種錯誤，而后者這種錯誤一般是原本的訪問路徑不正確或者運營商劫持導致訪問路徑錯誤。

2、按圖索驥：track nginx source code

搜了下，網上貌似很少有人問到這個問題，即使問到了也貌似沒有明確的解答，當 STFW 和 RTFM 都不管用的時候，那就只有硬著頭皮看源碼了，按圖索驥，看看源碼中，何處拋出的?client sent invalid userid cookie 這個錯誤：

static?ngx_http_userid_ctx_t?* ngx_http_userid_get_uid(ngx_http_request_t?*r,?ngx_http_userid_conf_t?*conf) { ...ngx_log_debug1(NGX_LOG_DEBUG_HTTP,?r->connection->log,?0,"uid?cookie:?\"%V\"",?&ctx->cookie);if?(ctx->cookie.len?<?22)?{cookies?=?r->headers_in.cookies.elts;ngx_log_error(NGX_LOG_ERR,?r->connection->log,?0,"client?sent?too?short?userid?cookie?\"%V\"",&cookies[n]->value);return?ctx;}src?=?ctx->cookie;/**?we?have?to?limit?the?encoded?string?to?22?characters?because*??1)?cookie?may?be?marked?by?"userid_mark",*??2)?and?there?are?already?the?millions?cookies?with?a?garbage*?????instead?of?the?correct?base64?trail?"=="*/src.len?=?22;dst.data?=?(u_char?*)?ctx->uid_got;if?(ngx_decode_base64(&dst,?&src)?==?NGX_ERROR)?{cookies?=?r->headers_in.cookies.elts;ngx_log_error(NGX_LOG_ERR,?r->connection->log,?0,"client?sent?invalid?userid?cookie?\"%V\"",&cookies[n]->value);return?ctx;}... }ngx_int_t ngx_decode_base64(ngx_str_t?*dst,?ngx_str_t?*src) {static?u_char???basis64[]?=?{77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?62,?77,?77,?77,?63,52,?53,?54,?55,?56,?57,?58,?59,?60,?61,?77,?77,?77,?77,?77,?77,77,??0,??1,??2,??3,??4,??5,??6,??7,??8,??9,?10,?11,?12,?13,?14,15,?16,?17,?18,?19,?20,?21,?22,?23,?24,?25,?77,?77,?77,?77,?77,77,?26,?27,?28,?29,?30,?31,?32,?33,?34,?35,?36,?37,?38,?39,?40,41,?42,?43,?44,?45,?46,?47,?48,?49,?50,?51,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77,?77};return?ngx_decode_base64_internal(dst,?src,?basis64); }static?ngx_int_t ngx_decode_base64_internal(ngx_str_t?*dst,?ngx_str_t?*src,?const?u_char?*basis) { ...for?(len?=?0;?len?<?src->len;?len++)?{if?(src->data[len]?==?'=')?{break;}if?(basis[src->data[len]]?==?77)?{return?NGX_ERROR;}}if?(len?%?4?==?1)?{return?NGX_ERROR;}s?=?src->data;d?=?dst->data;while?(len?>?3)?{*d++?=?(u_char)?(basis[s[0]]?<<?2?|?basis[s[1]]?>>?4);*d++?=?(u_char)?(basis[s[1]]?<<?4?|?basis[s[2]]?>>?2);*d++?=?(u_char)?(basis[s[2]]?<<?6?|?basis[s[3]]);s?+=?4;len?-=?4;}...return?NGX_OK; }

可以看到，源碼中會對傳入的 cookieId 做 base64 合法性校驗，如果沒有通過校驗，則會拋出?client sent invalid userid cookie 錯誤，并按 HttpUseridModule 的邏輯重新分配新的 cookieId。

3、測試驗證

為了證明上述推斷的正確性，并解決上述的錯誤，我們只需要找出沒通過校驗的地方，并構造測試用例驗證即可。

我們取一條正常的請求中的 cookie：

idooxx=05dvZ1ODTpI+FjiILHYwAg==;?__ag_cm_=1408028234222;?__utma=253535702.161ooxx51834.1401114262.1408099300.1408187334.7;?__utmz=253535702.1401114262.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);?_bu=201104111325386d88c794;?city=bj;?ooxxhome=bj;?myfeet_tooltip=end;?new_session=1;?init_refer=;?ipcity=bj%7C%u5317%u4EAC;?__utmb=253535702.3.9.1408187335363;?__utmc=253535702

用上述正確的對比錯誤的 cookie，可以看到，cookieId(idooxx) 中包含了雙引號，而導致 cookieId 沒有通過 base64 合法性校驗的可能正是包含了 非 base64 編碼字符串。下面我們來驗證下，手動在瀏覽器中構造一個不合法 cookie，看看是不是有同樣的問題。

由于 base64 編碼只包含 64 個字符：大小寫52 + 數字10 + 2個額外字符+/ ?一共64個字符。如果我們客戶端發送的 cookieId 中包含了上述非 64 字符集中的字符，那么 nginx HttpUseridModule 模塊就會校驗后認為請求非法，并會重新非配 cookieId。

4、解決方案

原因找到了，要解決起來就不難了，其實分析這些錯誤有個共性，就是這些錯誤都是由移動端產生的，pc 端基本沒有，因為 pc 端的瀏覽器請求的參數都是規范的，而移動端的很多都是 RD 自己拼接然后發送的，難免會不符合規范，有則改之。

5、Refer：

[1]?nginx-1.7.3/src/http/modules/ngx_http_userid_filter_module.c

http://lxr.nginx.org/source/src/http/modules/ngx_http_userid_filter_module.c

[2] nginx-1.7.3/src/core/ngx_string.c

http://lxr.nginx.org/source/src/core/ngx_string.c

[3] Errors using HttpUseridModule

http://www.serverphorums.com/read.php?5,856195

[4]?Base64編碼/解碼器

http://base64.xpcha.com/

[5]?ngx_http_userid_module模塊基本指令整理

http://www.iigrowing.cn/ngx-http-userid-module-mo-kuai-ji-ben-zhi-ling-zheng-li.html

轉載于:https://my.oschina.net/leejun2005/blog/302443

總結

以上是生活随笔為你收集整理的Nginx log error：client sent invalid userid cookie的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。