openresty CPU使用率高，上传火焰体，求分析

level077_0b9b

hi all：

近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：

nginx version: openresty/1.11.2.1

built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)

built with OpenSSL 1.0.2h 3 May 2016

TLS SNI support enabled

Attachment: x.svg
Description: image/svg

spacewanderlzx

查了下，这两个热点函数都属于 SSL handshake 的一部分。
能否在使用率很高的时候抓下包，看看具体的请求情况？
另外，SSL handshake 有没有做 session reuse 之类的优化？

在 2017年9月12日上午10:02，level077 <lev...@gmail.com>写道：

hi all：
近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：
nginx version: openresty/1.11.2.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
built with OpenSSL 1.0.2h 3 May 2016
TLS SNI support enabled

--

level077_0b9b

session reuse是开启的。

现象是这样的：有很多恶意IP同时大量访问，虽然都在access阶段回复403了，但是请求还在。

抓包看了下，都是要进行ssl 完全握手的。但跟以往看到的不同，这里用的是session ticket，以前没怎么看到。

在 2017年9月12日星期二 UTC+8下午12:25:40，Zexuan Luo写道：

查了下，这两个热点函数都属于 SSL handshake 的一部分。
能否在使用率很高的时候抓下包，看看具体的请求情况？
另外，SSL handshake 有没有做 session reuse 之类的优化？

在 2017年9月12日上午10:02，level077 <leve...@gmail.com>写道：
hi all：
近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：
nginx version: openresty/1.11.2.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
built with OpenSSL 1.0.2h 3 May 2016
TLS SNI support enabled

--

spacewanderlzx

既然是恶意IP，估计对方也不会让你有机会 reuse session 了（比如传个匹配不了的 session ticket）

你可以在 certificate_by_lua* 阶段就把这些 IP 给 ban 掉，避免完全握手。
有一个 pr 实现了在这个阶段获取客户端IP地址，https://github.com/openresty/lua-resty-core/pull/139
大体功能已经基本可用了。
这个修改并不跟 OpenResty 耦合，所以除了直接 patch 到 OpenResty 之外，更适当的做法是放到独立的 Nginx C module 里面。

当然目前直接可用的办法是先在 http 层面以下把这些恶意IP ban 掉。

在 2017年9月12日下午3:48，level077 <lev...@gmail.com>写道：

session reuse是开启的。
现象是这样的：有很多恶意IP同时大量访问，虽然都在access阶段回复403了，但是请求还在。
抓包看了下，都是要进行ssl 完全握手的。但跟以往看到的不同，这里用的是session ticket，以前没怎么看到。

在 2017年9月12日星期二 UTC+8下午12:25:40，Zexuan Luo写道：
查了下，这两个热点函数都属于 SSL handshake 的一部分。
能否在使用率很高的时候抓下包，看看具体的请求情况？
另外，SSL handshake 有没有做 session reuse 之类的优化？

在 2017年9月12日上午10:02，level077 <leve...@gmail.com>写道：
hi all：
近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：
nginx version: openresty/1.11.2.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
built with OpenSSL 1.0.2h 3 May 2016
TLS SNI support enabled

--

--

level077_0b9b

这个解决方案了解过。现在是想了解下CPU高的原因，是不是这个造成的。

在 2017年9月12日星期二 UTC+8下午4:15:37，Zexuan Luo写道：

既然是恶意IP，估计对方也不会让你有机会 reuse session 了（比如传个匹配不了的 session ticket）

你可以在 certificate_by_lua* 阶段就把这些 IP 给 ban 掉，避免完全握手。
有一个 pr 实现了在这个阶段获取客户端IP地址，https://github.com/openresty/lua-resty-core/pull/139
大体功能已经基本可用了。
这个修改并不跟 OpenResty 耦合，所以除了直接 patch 到 OpenResty 之外，更适当的做法是放到独立的 Nginx C module 里面。

当然目前直接可用的办法是先在 http 层面以下把这些恶意IP ban 掉。

在 2017年9月12日下午3:48，level077 <leve...@gmail.com>写道：
session reuse是开启的。
现象是这样的：有很多恶意IP同时大量访问，虽然都在access阶段回复403了，但是请求还在。
抓包看了下，都是要进行ssl 完全握手的。但跟以往看到的不同，这里用的是session ticket，以前没怎么看到。

在 2017年9月12日星期二 UTC+8下午12:25:40，Zexuan Luo写道：
查了下，这两个热点函数都属于 SSL handshake 的一部分。
能否在使用率很高的时候抓下包，看看具体的请求情况？
另外，SSL handshake 有没有做 session reuse 之类的优化？

在 2017年9月12日上午10:02，level077 <leve...@gmail.com>写道：
hi all：
近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：
nginx version: openresty/1.11.2.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
built with OpenSSL 1.0.2h 3 May 2016
TLS SNI support enabled

--

--

spacewanderlzx

很有可能是这个原因造成的。因为占比最高的这两个函数是在 SSL handshake 的过程中调用的。

在 2017年9月12日下午7:35，level077 <lev...@gmail.com>写道：

这个解决方案了解过。现在是想了解下CPU高的原因，是不是这个造成的。

在 2017年9月12日星期二 UTC+8下午4:15:37，Zexuan Luo写道：
既然是恶意IP，估计对方也不会让你有机会 reuse session 了（比如传个匹配不了的 session ticket）

你可以在 certificate_by_lua* 阶段就把这些 IP 给 ban 掉，避免完全握手。
有一个 pr 实现了在这个阶段获取客户端IP地址，https://github.com/openresty/lua-resty-core/pull/139
大体功能已经基本可用了。
这个修改并不跟 OpenResty 耦合，所以除了直接 patch 到 OpenResty 之外，更适当的做法是放到独立的 Nginx C module 里面。

当然目前直接可用的办法是先在 http 层面以下把这些恶意IP ban 掉。

在 2017年9月12日下午3:48，level077 <leve...@gmail.com>写道：
session reuse是开启的。
现象是这样的：有很多恶意IP同时大量访问，虽然都在access阶段回复403了，但是请求还在。
抓包看了下，都是要进行ssl 完全握手的。但跟以往看到的不同，这里用的是session ticket，以前没怎么看到。

在 2017年9月12日星期二 UTC+8下午12:25:40，Zexuan Luo写道：
查了下，这两个热点函数都属于 SSL handshake 的一部分。
能否在使用率很高的时候抓下包，看看具体的请求情况？
另外，SSL handshake 有没有做 session reuse 之类的优化？

在 2017年9月12日上午10:02，level077 <leve...@gmail.com>写道：
hi all：
近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：
nginx version: openresty/1.11.2.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
built with OpenSSL 1.0.2h 3 May 2016
TLS SNI support enabled

--

--

--

lihang_net

最终的问题确定了吗？

在 2017年9月12日星期二 UTC+8上午10:02:22，level077写道：

hi all：
近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：
nginx version: openresty/1.11.2.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
built with OpenSSL 1.0.2h 3 May 2016
TLS SNI support enabled

zx827882285

这个应该是openssl函数导致的。 https://mta.openssl.org/pipermail/openssl-users/2019-March/010014.html

我用最新的nginx1.16.1 和openssl 进行构建 --with-http_ssl_module --with-openssl=/git/openssl-1.1.1c，遇到和你一样的问题

分别关闭和开启TLS1.3，qps差距非常大，用火焰图抓取后发现都是耗在bn_sqr8x_internal 和 mul4x_internal函数上

请问这个问题后续有排查到或者有什么线索吗？如果有，我想我可以少走很多弯路, 期待你的回应

On Tuesday, September 12, 2017 at 10:02:22 AM UTC+8, level077 wrote:

hi all：
近期遇到了一次openresty CPU使用率很高，超过90%的情况，%user超60%，绘制了下火焰图，其中bn_sqr8x_internal 和 mul4x_internal占比很高，但是没有更多的堆栈信息，不知有人了解不？

openresty的版本信息：
nginx version: openresty/1.11.2.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC)
built with OpenSSL 1.0.2h 3 May 2016
TLS SNI support enabled