Nginx 配合 CloudFlare 获取真实 IP 并限制访问

在最近一次网站部署中,考虑到安全因素,希望将源站完全隐藏在 CF 后,只允许 CF 访问,并尽可能的减少信息泄漏。

获取真实客户端 IP

由于经过 CloudFlare 代理后,Nginx 看到的 remote ip 其实是 CF 的 IP 地址。因此需要通过 Nginx 的 ngx_http_realip_module,还原出真实的客户端 IP。这一步在 CloudFlare 有详细的文档说明

简单来说,当发现请求 IP 为 CF 的 IP 段时,读取 CF-Connecting-IP 头,并将其中的 IP 设置为客户端 IP。CF 的 IP 段可以通过 API 获取。以下是一个脚本可以生成相关的配置:

#!/bin/bash

# 脚本:获取 Cloudflare IP 列表并生成 Nginx 配置

# 输出文件
IP_CONFIG_FILE="cf_ips.conf"

# 清空输出文件
> "$IP_CONFIG_FILE"

# Cloudflare IP 列表 API 端点
CLOUDFLARE_API_URL="https://api.cloudflare.com/client/v4/ips"

# 生成 set_real_ip_from 配置
echo "# Cloudflare IPv4 IPs" >> "$IP_CONFIG_FILE"
curl -s "$CLOUDFLARE_API_URL" | jq -r '.result.ipv4_cidrs[]' | while read -r ip; do
    echo "set_real_ip_from $ip;" >> "$IP_CONFIG_FILE"
done

echo -e "\n# Cloudflare IPv6 IPs" >> "$IP_CONFIG_FILE"
curl -s "$CLOUDFLARE_API_URL" | jq -r '.result.ipv6_cidrs[]' | while read -r ip; do
    echo "set_real_ip_from $ip;" >> "$IP_CONFIG_FILE"
done

# 添加 real_ip_header 配置
echo -e "\n# Set real IP header" >> "$IP_CONFIG_FILE"
echo "real_ip_header CF-Connecting-IP;" >> "$IP_CONFIG_FILE"

脚本运行后会生成 cf_ips.conf 文件,内含 set_real_ip_fromreal_ip_header 配置,在 httpinclude 该文件,即可自动为所有 server 自动设置真实客户端 IP。

限制仅 CloudFlare IP 访问

解决了真实客户端 IP 的问题后,接下来就是如何做到仅限 CF IP 访问。由于该 Nginx 托管了多个 server,因此并不希望直接从防火墙层面拒绝所有非 CF IP 访问。那么从 Nginx 侧,第一时间想到的就是用 ngx_http_access_module 的方式,仅放过 CF IP 段:

# Cloudflare IPv4 Allow
allow 173.245.48.0/20;
allow 103.21.244.0/22;
allow 103.22.200.0/22;
allow 103.31.4.0/22;
allow 141.101.64.0/18;
allow 108.162.192.0/18;
allow 190.93.240.0/20;
allow 188.114.96.0/20;
allow 197.234.240.0/22;
allow 198.41.128.0/17;
allow 162.158.0.0/15;
allow 104.16.0.0/13;
allow 104.24.0.0/14;
allow 172.64.0.0/13;
allow 131.0.72.0/22;

# Cloudflare IPv6 Allow
allow 2400:cb00::/32;
allow 2606:4700::/32;
allow 2803:f800::/32;
allow 2405:b500::/32;
allow 2405:8100::/32;
allow 2a06:98c0::/29;
allow 2c0f:f248::/32;

# Default deny
deny all;

但是添加了这段配置后,发现不论是否通过 CF 访问,所有请求均会被拦截,返回 403。搜索相关文章1后发现,这是因为 ngx_http_realip_module 已经先执行完毕了,此时 ngx_http_access_module 拿到的已经是被修改了的真实客户端 IP,自然无法通过检测,被拒绝访问。

为了解决该问题,我们需要使用其他手段来进行访问控制。查阅相关资料后发现,ngx_http_geo_module 是个非常好的选择。相关配置如下:

geo $realip_remote_addr $is_cf {
  default 0;
  # Cloudflare IPv4 Allow
  173.245.48.0/20 1;
  103.21.244.0/22 1;
  103.22.200.0/22 1;
  103.31.4.0/22 1;
  141.101.64.0/18 1;
  108.162.192.0/18 1;
  190.93.240.0/20 1;
  188.114.96.0/20 1;
  197.234.240.0/22 1;
  198.41.128.0/17 1;
  162.158.0.0/15 1;
  104.16.0.0/13 1;
  104.24.0.0/14 1;
  172.64.0.0/13 1;
  131.0.72.0/22 1;

  # Cloudflare IPv6 Allow
  2400:cb00::/32 1;
  2606:4700::/32 1;
  2803:f800::/32 1;
  2405:b500::/32 1;
  2405:8100::/32 1;
  2a06:98c0::/29 1;
  2c0f:f248::/32 1;
}

其中,$realip_remote_addrngx_http_realip_module 提供的变量,存储了原始的客户端地址。通过 CF 访问的情况下,这个变量存储的就是原始的 CF 地址。$is_cf 是用于储存中间结果的变量。如果原始客户端地址在 CF IP 段,则会被设置为 1,否则为 0。

有了这个变量之后,我们就可以使用 ngx_http_rewrite_module 来进行判断,并拒绝访问。在需要的地方增加如下代码:

if ($is_cf = 0) {
    return 444;
}

即可拒绝掉所有非 CF 访问的情况。

使用 OpenResty

如果在使用 OpenResty,那么有更简单的方式2可以做这个事情。借助 access_by_lua_block,我们可以直接在 lua 里访问相关变量进行判断,并拒绝非 CF 的访问:

access_by_lua_block {
    if ngx.var.remote_addr == ngx.var.realip_remote_addr then
            return ngx.exit(ngx.HTTP_FORBIDDEN)
    end
}

原理其实也很简单,如果 ngx.var.remote_addrngx.var.realip_remote_addr 是相同的,则证明 ngx_http_realip_module 没有起作用,那么说明原始访问 IP 一定不在 CF IP 段内。

注意事项

  1. 有条件的情况下(即 Nginx 所有 server 都托管在 CF),应使用防火墙直接拒绝所有非 CF IP 的 TCP 链接
  2. 由于 if 指令只能使用在 serverlocation 使用,因此该方法在多个 server 内,需要重复配置
  3. 由于 ssl_reject_handshake 无法在 if 内使用,因此如果攻击者猜对了 server_name,那么证书信息依然会泄漏,存在被探测到源站的可能

参考文档

  1. https://serverfault.com/questions/601339/how-do-i-deny-all-requests-not-from-cloudflare/826428#826428 ↩︎
  2. https://stackoverflow.com/questions/39176931/nginx-allowdeny-realip-remote-addr/39183303#39183303 ↩︎

QNAP 新版 License Center 校验流程逆向

最近新添置了两个支持 ONVIF 协议的摄像头,想使用 QNAP 的 QVR 进行录像。但是打开 QVR 发现,只能添加两个通道,后续新的通道需要按年付费解锁。依稀记得原先是有 8 个免费通道可用的,于是打开官方文档,发现:

系统软件授权
QTSQVR Pro自带 8 通道
QTSQVR Elite自带 2 通道
QuTS heroQVR Elite自带 2 通道

原来官方提供的 8 通道 QVR Pro 只支持 QTS 系统,不支持基于 ZFS 的 QuTS hero 系统。既然官方不支持,那只能自己动手了。

TL; DR

  1. GPT 太好用了,大大提升逆向效率
  2. 新版校验用的 Public Key 经过简单的凯撒密码加密后打包在 libqlicense.so
  3. LIF 文件的 floating 相关字段需要干掉,否则会联机校验

激活流程

在研究的过程中,发现已有前人详细分析了激活流程的各个步骤,分析了各个文件的存储、编码、加密、验证格式,并编写了相关脚本和代码。具体文章在这里,此处不多做赘述:

https://jxcn.org/2022/03/qnap-license

尝试动手

参考文章,尝试在 NAS 上进行操作。结果发现,找不到文章中提及的 qlicense_public_key.pem 文件,全盘搜索后发现依然找不到该文件。查看文章评论发现,似乎官方在 23 年左右修改了一次校验逻辑,去掉了该文件。所有 23 年之后发布的版本,都无法使用替换 key 文件的方式进行激活。

重新分析

虽然官方修改了相关逻辑,但是有前人经验参考,还是很快发现了关键所在。

先用 IDA 打开 qlicense_tool ,找到离线激活的处理函数,发现对输入进行简单处理后直接调用了 qcloud_license_offline_activate 函数,位于 libqlicense.so 动态链接库中。这个函数在几层调用之后,最终调用了 qcloud_license_internal_verify 函数,对 LIF 文件的签名进行了计算。

由于静态分析不太容易理清逻辑,于是上 GDB 准备直接调试。找了下发现 MyQNAP Repo 里有编译好的 GDB,但是安装却失败了。研究了下发现是作者把 X86 和 X41 的链接搞反了。X86 下载到的包是 X41 的,导致安装失败。于是手动下载了正确的包之后安装,一切顺利。

通过 gdb 调试发现,qcloud_license_internal_verify 函数的第一个入参就是校验用的 Public Key,打出来长这样:

-----BEGIN PUBLIC KEY-----
MHYwEAYHKoZIzj0CAQYFK4EEACIDYgAEDJcPoMIFyYDlhTUzNSeT/+3ZKcByILoI
Fw8mLv07Hpy2I5qgAGQu66vF3VUjFKgpDDFKVER9jwjjmXUOpoCXX4ynvFUpEM25
ULJE86Z6WjcLqyG03Mv6d3GPYNl/cJYt
-----END PUBLIC KEY-----

通过 hook fopen 函数,想找到这个 key 存储在哪个文件,但是发现并没有结果。于是想到,这段 key 可能被打进了 so 文件本身,于是通过 Strings 搜索,但是依然没有找到相关字符串。

一筹莫展之际,在调用链路上乱点,突然注意到这样一段奇怪的代码(IDA 还原得出):

    while ( 1 )
    {
      result[v3] = (v1[v3] + 95) % 128;
      if ( ++v3 == 359 )
        break;
      result = (_BYTE *)*a1;
    }

多看两眼之后意识到,这就是凯撒密码。(虽然凯撒密码现在看来其实更应该算是编码而非加密,但是考虑到确实有相关定义,因此后续均表述为加密和解密。)也就是说,之所以在 Strings 内找不到相关字符串,是因为写入的是通过凯撒密码加密后的字符串。于是把这段丢给 GPT,让它写个加密和解密的代码:

# -*- coding: utf-8 -*-

def decode(input_string):
    result = []
    for char in input_string:
        # 将每个字符的 ASCII 值加 95,然后对 128 取模
        encoded_char = (ord(char) + 95) % 128
        result.append(chr(encoded_char))
    return ''.join(result)

def encode(encoded_string):
    result = []
    for char in encoded_string:
        # 逆向解码:恢复原始字符
        decoded_char = (ord(char) - 95) % 128
        result.append(chr(decoded_char))
    return ''.join(result)

original_text = """-----BEGIN PUBLIC KEY-----
MHYwEAYHKoZIzj0CAQYFK4EEACIDYgAEDJcPoMIFyYDlhTUzNSeT/+3ZKcByILoI
Fw8mLv07Hpy2I5qgAGQu66vF3VUjFKgpDDFKVER9jwjjmXUOpoCXX4ynvFUpEM25
ULJE86Z6WjcLqyG03Mv6d3GPYNl/cJYt
-----END PUBLIC KEY-----"""
encoded_text = encode(original_text)
decoded_text = decode(encoded_text)

print("Original:", original_text)
print("Encoded:", encoded_text)
print("Decoded:", decoded_text)

跑了一下,得到实际存储的字符串:

NNNNNcfhjoAqvcmjdAlfzNNNNN+niz\u0018fbzil\u0010{j\u001b\u000bQdbrzglUffbdjez\bbfek\u0004q\u0010njg\u001aze\r\tuv\u001bot\u0006uPLT{l\u0004c\u001ajm\u0010j+g\u0018Y\u000em\u0017QXi\u0011\u001aSjV\u0012\bbhr\u0016WW\u0017gTwv\u000bgl\b\u0011eeglwfsZ\u000b\u0018\u000b\u000b\u000eyvp\u0011\u0010dyyU\u001a\u000f\u0017gv\u0011fnSV+vmkfYW{Wx\u000b\u0004m\u0012\u001ahQTn\u0017W\u0005Thqzo\rP\u0004kz\u0015+NNNNNfoeAqvcmjdAlfzNNNNN

由于开头和结尾的 ----- 会被加密为 NNNNN 因此直接在 Strings 中搜索,顺利定位到相关资源,位于 .rodata 段 38B40 的位置,长度 212。

接下来操作就简单了,生成一对新的 key 之后,直接替换指定位置即可。注意,由于长度是写死在代码里的,因此二者必须等长,否则可能会出现无法预料的错误。

再丢给 GPT 写个十六进制替换的脚本:

# -*- coding: utf-8 -*-

import binascii

def hex_to_bytes(hex_str):
    """将16进制字符串转换为字节数据。"""
    return binascii.unhexlify(hex_str)

def patch_file(file_path, search_hex, replace_hex):
    # 将16进制模式转换为字节数据
    search_bytes = hex_to_bytes(search_hex)
    replace_bytes = hex_to_bytes(replace_hex)
    
    # 检查替换块的长度是否匹配
    if len(search_bytes) != len(replace_bytes):
        raise ValueError("Length mismatch! 搜索模式和替换内容长度必须相同!")

    # 读取文件内容
    with open(file_path, "rb") as f:
        data = f.read()

    # 查找并替换内容
    patched_data = data.replace(search_bytes, replace_bytes)

    # 如果没有找到匹配的内容
    if data == patched_data:
        print("No Match. 没有找到匹配的内容。")
    else:
        # 将修改后的内容写回文件
        with open(file_path, "wb") as f:
            f.write(patched_data)
        print("Patch success. 文件已成功更新。")

# 使用示例
file_path = "libqlicense.so"           # 需要打补丁的文件路径
old_hex = "4e4e4e4e4e6366686a6f417176636d6a64416c667a4e4e4e4e4e2b6e697a1866627a696c107b6a1b0b516462727a676c55666662646a657a086266656b0471106e6a671a7a650d0975761b6f740675504c547b6c04631a6a6d106a2b6718590e6d17515869111a536a56120862687216575717675477760b676c08116565676c7766735a0b180b0b0e7976701110647979551a0f17677611666e53562b766d6b6659577b57780b046d121a6851546e1757055468717a6f0d50046b7a152b4e4e4e4e4e666f65417176636d6a64416c667a4e4e4e4e4e"              # 要搜索的16进制字符串
new_hex = "4e4e4e4e4e6366686a6f417176636d6a64416c667a4e4e4e4e4exxx4e4e4e4e4e666f65417176636d6a64416c667a4e4e4e4e4e"             # 替换为的16进制字符串

# 执行替换操作
patch_file(file_path, old_hex, new_hex)

这里使用 Hex Encoding 的原因是加密后的字符串存在一些非 ASCII 字符。

替换后,用原作者的相关脚本和工具,生成了一个 LIF,尝试使用 qlicense_tool 激活。此时发现,激活死活失败,但是调试发现 verify 实际已经过了。研究了好久之后,发现是 Console Management 工具导致的。由于 qlicense_tool 在激活过程中会运行被激活服务的脚本检测 License 正确性,而 Console Management 拦截了相关命令,导致返回包不是合法的 json,导致失败。在系统设置内关闭 Console Management 后,激活成功。

检测报错

本以为到此激活就成功了。结果打开许可证中心之后,发现许可证无效了。查阅相关日志,发现许可证中心发送了一个 POST 请求到 https://license.myqnapcloud.io/v1.1/license/device/installed ,然后报错许可不属于该设备,然后将许可改为失效。

阅读原作者相关文章,结合代码,发现是因为原作者是为了 QuTS Cloud 设计的代码,由于 Cloud 版没有离线激活功能,所以会定期刷新 Token,这里一刷新就发现许可有问题了。于是修改代码,将 LIF 内的 floating 相关字段全部干掉。包括:

FloatingUUID
FloatingToken
LicenseCheckPeriod

重新生成 LIF 文件,再次激活,已经不会向 myqnapcloud 验证激活信息了。

OpenResty AES 函数密钥生成原理

最近遇到一个场景,需要在 OpenResty 里使用 AES 对数据进行加密。但是看了一下官方提供的 AES 库,如果数据密码的话,并没有返回实际使用的 key 和 IV,因此查看了一下源码,研究了一下 key 生成的方式,方便其他语言使用。

密钥生成逻辑的核心代码在这:

function _M.new(self, key, salt, _cipher, _hash, hash_rounds, iv_len, enable_padding)

...

    local _hash = _hash or hash.md5
    local hash_rounds = hash_rounds or 1

...

        if C.EVP_BytesToKey(_cipher.method, _hash, salt, key, #key,
                            hash_rounds, gen_key, gen_iv)
            ~= _cipherLength
        then
            return nil, "failed to generate key and iv"
        end
end

其中最核心的部分就是使用了 EVP_BytesToKey 这个函数,进行密钥扩展。这个函数是 OpenSSL 库提供的函数,相关说明在这:

https://www.openssl.org/docs/man3.1/man3/EVP_BytesToKey.html

注意!该函数并不安全!一般不建议在生产中使用该函数!应当使用安全的密钥衍生函数(KDF)!

阅读文档,该函数的主要做法就是对提供的密码进行 hash,如果长度不够 key 或 iv 的要求,则继续进行 hash,直到长足足够为止。

第一轮 hash 直接拼接给定的密码和 salt,从第二轮开始,则将上一轮的结果附加在密码和 salt 前,然后再次进行 hash 操作。注意这里从第二轮开始附加的上一轮结果是二进制结果,如果希望手动使用工具计算的话,需要将 hex 编码或 base64 编码后的结果先进行解码,再附加在输入前。

用 Go 模拟这个过程的代码如下:

package main

import (
    "crypto/sha256"
    "fmt"
)

// EVPBytesToKey 模拟 OpenSSL EVP_BytesToKey 方法
func EVPBytesToKey(password, salt []byte, keyLen, ivLen int) (key, iv []byte) {
    var (
        concatenatedHashes []byte
        previousHash       []byte
        currentHash        []byte
        hash               = sha256.New()
    )

    for len(concatenatedHashes) < keyLen+ivLen {
        hash.Reset()

        // 如果不是第一轮,将上一轮的哈希值加到当前哈希的输入中
        if previousHash != nil {
            hash.Write(previousHash)
        }

        // 加入密码和盐值
        hash.Write(password)
        hash.Write(salt)

        // 当前哈希
        currentHash = hash.Sum(nil)

        // 添加到累积哈希中
        concatenatedHashes = append(concatenatedHashes, currentHash...)

        // 为下一轮准备
        previousHash = currentHash
    }

    // 提取密钥和 IV
    key = concatenatedHashes[:keyLen]
    iv = concatenatedHashes[keyLen : keyLen+ivLen]
    return key, iv
}

func main() {
    password := []byte("password")
    salt := []byte("salt")
    keyLen := 32 // AES-256 需要的密钥长度
    ivLen := 16  // AES 的 IV 长度

    key, iv := EVPBytesToKey(password, salt, keyLen, ivLen)
    fmt.Printf("Key: %x\nIV: %x\n", key, iv)
}

腾讯云云函数 SCF 与轻量服务器互通指南

去年末腾讯云轻量服务器推出了内网互联功能,但是好像有很多小伙伴不太清楚用法。因此写本文给大家一些使用思路。

本文基于官方文档 https://cloud.tencent.com/document/product/1207/56847

注意事项

  1. 轻量内网互联功能、云联网及 VPC 等功能本身不收费,但若本地互联带宽超过 5Gbps 或需要跨地域互联,则需要收取相关带宽费用。因此本文仅做同地域互联展示
  2. 由于轻量的内网 IP 无法自定义,所以建议先购买好需要的轻量服务,再规划内网其他服务(如 SCF、MySQL 等)的网段,以避免内网 IP 冲突
  3. 若轻量云 VPC 的 CIDR 与云函数 VPC 的 CIDR 有重合,可能带来一些奇怪的访问不通的问题,建议在网段规划时直接避开重合段
  4. 云联网只是打通网络,实际端口访问还是受到防火墙限制。若出现访问不通,请检查轻量服务器的防火墙设置:https://cloud.tencent.com/document/product/1207/44577
  5. 已有云函数可以通过编辑函数配置加入 VPC,无需新建
  6. 该方法打通网络后,不仅可以做到云函数访问轻量云资源,同样反向访问也是可以的。如允许轻量云服务器访问 VPC 内的其他 CVM 或 MySQL、Kafka、Redis 等资源,但是要注意对应资源的安全组设置,需要放通轻量云服务器的相关网段

操作流程

轻量云内网互联

在对应区域购买轻量云服务,本文以北京区为例

购买完成后进入 内网互联 页面,可以看到对应区域的关联选项:

内网互通

点击关联云联网,弹出关联选择页面:

关联云联网

选择需要的云联网。若还未创建云联网,则点击新建

新建云联网

新建云联网时,由于我们只用本地带宽,因此服务质量直接选择白金即可。若有跨地域互联需求,则按照预算选择对应的服务质量。

下方的关联 VPC 实例可以先不填。直接点击右边的小叉删除即可。

新建完成后,回到关联云联网页面,选择对应的云联网并确认

关联申请成功

看到这里说明关联申请已成功提交。接下来需要进入云联网控制台同意关联申请。点击页面中的跳转链接即可快速跳转到对应的云联网控制台

云联网控制台

这里要注意,由于轻量服务器是处在腾讯云内部独立账号下,因此这里的所属账号可能与自己的账号不同,这是正常的。如果这里出现了多条记录,我们找对应时间为我们申请关联的时间,备注为 Lighthouse VPC 的申请记录,并点击同意。

接受申请后,状态变为绿色的已连接。

此时回到轻量云的控制台,刷新后会发现已关联成功

内网互联成功

到这里,轻量云和云联网的关联已全部完成。此处的内网 CIDR 需要记下,在后续的 VPC 创建中要用。

云函数 SCF 内网互联

接下来我们处理 SCF 与内网资源的互通。

首先我们需要一个 VPC 给 SCF 使用。如果已有规划好的 VPC,则可跳过新建 VPC 步骤。

打开 VPC 控制台,切换到对应的区域。这里使用北京区域。

新建 VPC

新建 VPC 时,有两个 CIDR 需要配置。一个是整个大 VPC 的 CIDR 范围,一个是单个子网的 CIDR 范围。还记得之前轻量的 CIDR 么?此处的大 VPC CIDR 可以包含轻量的 CIDR,但是子网的 CIDR 范围最好不要跟轻量的 CIDR 有重叠,否则需要对路由表进行细致的调整,还可能出现 IP 冲突,比较麻烦。

由于我们之前拿到的轻量的 CIDR 是 10.0.24.0/22,因此这里我们给子网分配 10.0.0.0/24,避免冲突。

新建 VPC 成功

接下来我们需要将这个 VPC 关联到刚才的云联网中。

回到云联网的控制台,在关联实例页面,选择新增实例

新增关联

依次选择私有网络-对应地域-对应 VPC,并确认。

关联完成

确认后即可看到我们刚刚新建的 VPC 和轻量的 VPC 均为已连接状态。

为了确保没有 CIDR 冲突,我们需要确认一下路由表状态。点击上方的路由表页面进行确认

云联网路由表

看到两条路由表均为有效且启用的状态,说明互联已完成。

若此处出现路由冲突,请参考官方文档解决。

云函数使用 VPC 网络

现在一切准备就绪,我们可以使用 SCF 访问轻量服务器了。

为了测试方便,我在轻量服务器上启动了一个 nginx 服务,并开启了对应的防火墙。这里的操作与互联无关,因此不再赘述。

现在来到云函数的控制台,在对应地域新建云函数。这里选择北京,使用 python 语言。

函数代码使用 python 写了一个简单的获取网页内容并输出:

# -*- coding: utf8 -*-
import json
import urllib.request
def main_handler(event, context):
    resp = urllib.request.urlopen("http://10.0.24.x") # 这里是轻量服务器的内网 IP
    print(resp.read())

在填写完函数内容后,展开下方的高级设置:

高级设置

我们需要关注的是这里的私有网络,其他设置按需调整即可,与互联无关。

我们勾选启用私有网络:

启用私有网络

待加载完成后,选择我们之前创建好并关联了云联网的私有网络,然后点击页面最下方的完成即可。

待函数部署成功后,查看函数配置,看到对应的 VPC 配置,即为配置成功。

函数配置

接下来测试一下函数是否可以跑通,进入函数代码页面,点击编辑器下方的测试:

函数测试

测试完成后,会在下方输出测试结果:

测试结果

可以看到,云函数成功通过内网拉到了位于轻量云服务器上的 nginx 服务的数据。

使用 Quartz 调度器遇到的一些问题

最近,线上运行的定时任务出现调度失败。调整了相关参数后,虽然遏制了调度失败的情况,却导致任务调度的延迟极度增加。同时还观察到,在多机部署的环境中,负载极不均匀,于是深入代码排查一番。

TL; DR

  1. 不要使用 Spring 提供的 org.springframework.scheduling.quartz.SchedulerFactoryBean#setTaskExecutor 方法自定义工作线程池
  2. 要注意 Spring 与 Quartz 的部分配置默认值不一致,如 org.quartz.threadPool.class
  3. 一般情况下使用 Quartz 提供的 SimpleThreadPool 配合参数 org.quartz.threadPool.threadCount 调整最大线程数即可
  4. 如果需要自定义工作线程池,则必须直接实现 org.quartz.spi.ThreadPool 接口,并一定要实现 blockForAvailableThreads 方法,支持阻塞等待
  5. 适当设置 org.quartz.scheduler.batchTriggerAcquisitionMaxCount 参数,使用批量能力降低 DB 交互带来的延迟

任务调度失败

问题现象

接用户反馈,一个一直正常运行的定时任务,在确认没有进行任何变动的情况下,却突然不再被调度了。经过确认,确实没有找到该任务的任何改动痕迹。因此怀疑问题是出在 Quartz 调度引擎上。

找出原因

看到这个现象,第一反应是 Quartz 里的 Trigger 异常了。因为 Quartz 对于所有状态是异常的 Trigger 都不会再次调度,表现为没有任何操作但是任务不执行。于是查看 QRTZ_TRIGGERS 表,筛选过后果然看到了 STATEERRORTRIGGER。根据 TRIGGER_NAMETRIGGER_GROUP 确定为用户反馈的任务所对应的触发器。

确定了问题是 TRIGGER_STATE 后,就要找到状态变化的点。先查看出现问题时的业务日志,可以看到有这样的记录穿插其中:

[2021-04-16 16:14:08.001][|][quartz-scheduler_QuartzSchedulerThread] ERROR o.s.s.q.LocalTaskExecutorThreadPool:runInThread:84 - Task has been rejected by TaskExecutor
 org.springframework.core.task.TaskRejectedException: Executor [java.util.concurrent.ThreadPoolExecutor@ef3310e[Running, pool size = 50, active threads = 50, queued tasks = 100, completed tasks = 20]] did not accept task: org.quartz.core.JobRunShell@5841bfb6
         at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:324)
         at org.springframework.scheduling.quartz.LocalTaskExecutorThreadPool.runInThread(LocalTaskExecutorThreadPool.java:80)
         at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:398)
 Caused by: java.util.concurrent.RejectedExecutionException: Task org.quartz.core.JobRunShell@5841bfb6 rejected from java.util.concurrent.ThreadPoolExecutor@ef3310e[Running, pool size = 50, active threads = 50, queued tasks = 100, completed tasks = 20]
         at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
         at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
         at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
         at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:321)
         … 2 common frames omitted
 [2021-04-16 16:14:08.001][|][quartz-scheduler_QuartzSchedulerThread] ERROR o.quartz.core.QuartzSchedulerThread:run:403 - ThreadPool.runInThread() return false!

从日志里可以看到,有一些定时任务被线程池拒绝了。而我们的线程池中有 50 个工作线程,100 个等待队列。也就是说这台机器短时间内承担了 150 个以上的调度任务,就会导致线程池无法承受如此多的任务而导致后续的任务被拒绝执行。因此猜测这部分被拒绝执行的任务导致了 Quartz 的 Trigger 状态异常。

于是查找相关代码,可以看到有一共有四处修改状态为 ERROR 的代码。其中由于 retrieveJob 导致的错误暂时排除,因为 DB 中 Trigger 的数据都是高度相似的。如果是这里出了问题,那么一定是大批量的出现错误,而非个别任务。继续查找,找到如下逻辑:

JobRunShell shell = null;
try {
    // 创建触发器执行环境
    shell = qsRsrcs.getJobRunShellFactory().createJobRunShell(bndle);
    shell.initialize(qs);
} catch (SchedulerException se) {
    qsRsrcs.getJobStore().triggeredJobComplete(triggers.get(i), bndle.getJobDetail(), Trigger.CompletedExecutionInstruction.SET_ALL_JOB_TRIGGERS_ERROR);
    continue;
}

// 提交执行并检查提交结果
if (qsRsrcs.getThreadPool().runInThread(shell) == false) {
    // this case should never happen, as it is indicative of the
    // scheduler being shutdown or a bug in the thread pool or
    // a thread pool being used concurrently - which the docs
    // say not to do...
    getLog().error("ThreadPool.runInThread() return false!");
    qsRsrcs.getJobStore().triggeredJobComplete(triggers.get(i), bndle.getJobDetail(), Trigger.CompletedExecutionInstruction.SET_ALL_JOB_TRIGGERS_ERROR);
}

从这里可以看到,如果任务提交到线程池的时候失败了,那么就会导致任务被标记为 ERROR。而这刚好符合我们看到的日志现象。由于线程池等待队列满导致的提交异常这种情况只会在等待队列撑满之后才会发生,刚好符合大部分任务没有问题但少部分任务失败的情况,于是确定了问题的原因。

深入分析

虽然找到了调度失败的原因是由于线程池满引起的,但是经过计算,这并不是设计中应该出现的。因为在设计中,业务一共有三台机器分别调度任务,而总任务数量在 300~400 左右。期望中每台机器都应承载 1/3 左右的业务量,也就是约 100~140 个任务左右。在这种情况下,理论上每台机器的线程池都应刚好能满足业务需要的,不应该出现这种情况。而通过查看日志,会发现实际上大部分任务都由一台机器执行,另外两台只分配到了少量任务。这种倾斜直接导致了任务量最大的机器数量爆表,导致线程池处理不及时,进而导致任务提交失败,被 Quartz 标记为异常,停止调度。

误入歧途

既然找到了问题在于 Quartz 调度任务的速度太快,线程池来不及处理,于是想到通过参数配置降低 Quartz 调度线程投递任务的速度,并尝试调升队列缓冲来解决这个问题。通过阅读调度器的代码,找到如下逻辑:

@Override
public void run() {
    int acquiresFailed = 0;

    while (!halted.get()) {
        try {
            // do some process states check

            int availThreadCount = qsRsrcs.getThreadPool().blockForAvailableThreads();
            if(availThreadCount > 0) { // will always be true, due to semantics of blockForAvailableThreads...

                List<OperableTrigger> triggers;

                long now = System.currentTimeMillis();

                clearSignaledSchedulingChange();
                try {
                    triggers = qsRsrcs.getJobStore().acquireNextTriggers(
                            now + idleWaitTime, Math.min(availThreadCount, qsRsrcs.getMaxBatchSize()), qsRsrcs.getBatchTimeWindow());
                    acquiresFailed = 0;
                    if (log.isDebugEnabled())
                        log.debug("batch acquisition of " + (triggers == null ? 0 : triggers.size()) + " triggers");
                } catch (JobPersistenceException jpe) {
                    // do exception process
                    continue;
                } catch (RuntimeException e) {
                    // do exception process 
                    continue;
                }

                if (triggers != null && !triggers.isEmpty()) {

                    now = System.currentTimeMillis();
                    long triggerTime = triggers.get(0).getNextFireTime().getTime();
                    long timeUntilTrigger = triggerTime - now;
                    while(timeUntilTrigger > 2) {
                        synchronized (sigLock) {
                            if (halted.get()) {
                                break;
                            }
                            if (!isCandidateNewTimeEarlierWithinReason(triggerTime, false)) {
                                try {
                                    // we could have blocked a long while
                                    // on 'synchronize', so we must recompute
                                    now = System.currentTimeMillis();
                                    timeUntilTrigger = triggerTime - now;
                                    if(timeUntilTrigger >= 1)
                                        sigLock.wait(timeUntilTrigger);
                                } catch (InterruptedException ignore) {
                                }
                            }
                        }
                        if(releaseIfScheduleChangedSignificantly(triggers, triggerTime)) {
                            break;
                        }
                        now = System.currentTimeMillis();
                        timeUntilTrigger = triggerTime - now;
                    }

                    // do some check

                    if(goAhead) {
                        try {
                            List<TriggerFiredResult> res = qsRsrcs.getJobStore().triggersFired(triggers);
                            if(res != null)
                                bndles = res;
                        } catch (SchedulerException se) {
                            // do exception process
                            continue;
                        }

                    }

                    for (int i = 0; i < bndles.size(); i++) {
                        TriggerFiredResult result =  bndles.get(i);
                        TriggerFiredBundle bndle =  result.getTriggerFiredBundle();
                        Exception exception = result.getException();

                        // do some check

                        JobRunShell shell = null;
                        try {
                            shell = qsRsrcs.getJobRunShellFactory().createJobRunShell(bndle);
                            shell.initialize(qs);
                        } catch (SchedulerException se) {
                            qsRsrcs.getJobStore().triggeredJobComplete(triggers.get(i), bndle.getJobDetail(), CompletedExecutionInstruction.SET_ALL_JOB_TRIGGERS_ERROR);
                            continue;
                        }

                        if (qsRsrcs.getThreadPool().runInThread(shell) == false) {
                            // this case should never happen, as it is indicative of the
                            // scheduler being shutdown or a bug in the thread pool or
                            // a thread pool being used concurrently - which the docs
                            // say not to do...
                            getLog().error("ThreadPool.runInThread() return false!");
                            qsRsrcs.getJobStore().triggeredJobComplete(triggers.get(i), bndle.getJobDetail(), CompletedExecutionInstruction.SET_ALL_JOB_TRIGGERS_ERROR);
                        }

                    }

                    continue; // while (!halted)
                }
            } else { // if(availThreadCount > 0)
                // should never happen, if threadPool.blockForAvailableThreads() follows contract
                continue; // while (!halted)
            }

            long now = System.currentTimeMillis();
            long waitTime = now + getRandomizedIdleWaitTime();
            long timeUntilContinue = waitTime - now;
            synchronized(sigLock) {
                try {
                    if(!halted.get()) {
                        // QTZ-336 A job might have been completed in the mean time and we might have
                        // missed the scheduled changed signal by not waiting for the notify() yet
                        // Check that before waiting for too long in case this very job needs to be
                        // scheduled very soon
                        if (!isScheduleChanged()) {
                            sigLock.wait(timeUntilContinue);
                        }
                    }
                } catch (InterruptedException ignore) {
                }
            }

        } catch(RuntimeException re) {
            getLog().error("Runtime error occurred in main trigger firing loop.", re);
        }
    } // while (!halted)

    // drop references to scheduler stuff to aid garbage collection...
    qs = null;
    qsRsrcs = null;
}

这段是 Quartz 调度线程的主要逻辑,注意其中的这段:

triggers = qsRsrcs.getJobStore().acquireNextTriggers(
                            now + idleWaitTime, Math.min(availThreadCount, qsRsrcs.getMaxBatchSize()), qsRsrcs.getBatchTimeWindow());

这里可以看到,Quartz 每次从 DB 拉取的任务数量与线程池的可用线程数和一个参数 MaxBatchSize 有关。根据查阅到的一些文章,说此处 Quartz 会每次拉取线程数个任务。因此怀疑这里是由于工作线程池的线程数量过大,导致任务都被一台机器拉取,导致的负载不均衡。于是尝试调小线程池的参数,来缓解拉取任务过多的问题。这里要说下,这个怀疑是错误的!让我误入歧途。具体原因会在后面说明。

问题“解决“

通过调整此处线程池的参数,任务执行出错的问题再也没有出现。本以为所有的问题就这样解决了,没想到却引来了另一个更棘手的问题:调度延迟。

任务调度延迟

问题现象

接用户反馈,部分每分钟执行一次的定时任务,出现了同一分钟内执行两次的情况。在任务的执行历史里可以明显看到 12:01:09 有一次执行,12:01:22 的时候又出现了一次执行。

找出原因

由于 Quartz 调度器本身是不太容易犯重复调度这样的错误的,因此第一时间考虑是任务调度延迟导致的。通过观察用户的定时任务,发现实际上该任务在 11:59:02 12:01:09 和 12:01:22 分别调度一次。因此可以确定,12:01 的两次调度,一次为正常的调度,一次为 12:00 应当调度的任务但是因为某些原因延迟了。这样才导致整个调度看起来就像是在 12:01 的之后重复调度了一次。

那么现在的问题就在于调度延迟了。由于之前比较激进的调整过线程池的参数,因此这里还是主要考虑在线程池周边找问题。通过调大线程池的参数,可以明显的发现总体调度延迟飞速降低。但是在测试的过程中,还是在日志里发现了一点之前忽略的小问题:

[2021-04-16 20:27:00.051][|][threadPoolTaskExecutor-1] Execute task|1|1
[2021-04-16 20:27:00.100][|][threadPoolTaskExecutor-2] Execute task|1|2
[2021-04-16 20:27:00.157][|][threadPoolTaskExecutor-3] Execute task|1|3
[2021-04-16 20:27:00.213][|][threadPoolTaskExecutor-4] Execute task|1|4
[2021-04-16 20:27:00.268][|][threadPoolTaskExecutor-5] Execute task|1|5
[2021-04-16 20:27:00.323][|][threadPoolTaskExecutor-6] Execute task|1|6
[2021-04-16 20:27:00.379][|][threadPoolTaskExecutor-7] Execute task|1|7
[2021-04-16 20:27:00.437][|][threadPoolTaskExecutor-8] Execute task|1|8
[2021-04-16 20:27:00.492][|][threadPoolTaskExecutor-9] Execute task|1|9
[2021-04-16 20:27:00.554][|][threadPoolTaskExecutor-10] Execute task|1|10
[2021-04-16 20:27:00.610][|][threadPoolTaskExecutor-11] Execute task|1|11
[2021-04-16 20:27:00.667][|][threadPoolTaskExecutor-12] Execute task|1|12
[2021-04-16 20:27:00.721][|][threadPoolTaskExecutor-13] Execute task|1|13
[2021-04-16 20:27:00.775][|][threadPoolTaskExecutor-14] Execute task|1|14
[2021-04-16 20:27:00.831][|][threadPoolTaskExecutor-15] Execute task|1|15
[2021-04-16 20:27:00.885][|][threadPoolTaskExecutor-16] Execute task|1|16
[2021-04-16 20:27:00.937][|][threadPoolTaskExecutor-17] Execute task|1|17
[2021-04-16 20:27:00.991][|][threadPoolTaskExecutor-18] Execute task|1|18
[2021-04-16 20:27:01.044][|][threadPoolTaskExecutor-19] Execute task|1|19
[2021-04-16 20:27:01.098][|][threadPoolTaskExecutor-20] Execute task|1|20
[2021-04-16 20:27:01.152][|][threadPoolTaskExecutor-21] Execute task|1|21
[2021-04-16 20:27:01.206][|][threadPoolTaskExecutor-22] Execute task|1|22
[2021-04-16 20:27:01.261][|][threadPoolTaskExecutor-23] Execute task|1|23
[2021-04-16 20:27:01.315][|][threadPoolTaskExecutor-24] Execute task|1|24
[2021-04-16 20:27:01.372][|][threadPoolTaskExecutor-25] Execute task|1|25
[2021-04-16 20:27:01.427][|][threadPoolTaskExecutor-26] Execute task|1|26
[2021-04-16 20:27:01.481][|][threadPoolTaskExecutor-27] Execute task|1|27
[2021-04-16 20:27:01.536][|][threadPoolTaskExecutor-28] Execute task|1|28
[2021-04-16 20:27:01.590][|][threadPoolTaskExecutor-29] Execute task|1|29
[2021-04-16 20:27:01.644][|][threadPoolTaskExecutor-30] Execute task|1|30
[2021-04-16 20:27:01.698][|][threadPoolTaskExecutor-31] Execute task|1|31
[2021-04-16 20:27:01.757][|][threadPoolTaskExecutor-32] Execute task|1|32
[2021-04-16 20:27:01.811][|][threadPoolTaskExecutor-33] Execute task|1|33
[2021-04-16 20:27:01.866][|][threadPoolTaskExecutor-34] Execute task|1|34
[2021-04-16 20:27:01.920][|][threadPoolTaskExecutor-35] Execute task|1|35
[2021-04-16 20:27:01.973][|][threadPoolTaskExecutor-36] Execute task|1|36
[2021-04-16 20:27:02.031][|][threadPoolTaskExecutor-37] Execute task|1|37
[2021-04-16 20:27:02.086][|][threadPoolTaskExecutor-38] Execute task|1|38
[2021-04-16 20:27:02.139][|][threadPoolTaskExecutor-39] Execute task|1|39
[2021-04-16 20:27:02.194][|][threadPoolTaskExecutor-40] Execute task|1|40
[2021-04-16 20:27:02.247][|][threadPoolTaskExecutor-41] Execute task|1|41
[2021-04-16 20:27:02.301][|][threadPoolTaskExecutor-42] Execute task|1|42
[2021-04-16 20:27:02.354][|][threadPoolTaskExecutor-43] Execute task|1|43
[2021-04-16 20:27:02.407][|][threadPoolTaskExecutor-44] Execute task|1|44
[2021-04-16 20:27:02.460][|][threadPoolTaskExecutor-45] Execute task|1|45
[2021-04-16 20:27:02.513][|][threadPoolTaskExecutor-46] Execute task|1|46
[2021-04-16 20:27:02.567][|][threadPoolTaskExecutor-47] Execute task|1|47
[2021-04-16 20:27:02.620][|][threadPoolTaskExecutor-48] Execute task|1|48
[2021-04-16 20:27:02.680][|][threadPoolTaskExecutor-49] Execute task|1|49
[2021-04-16 20:27:02.734][|][threadPoolTaskExecutor-50] Execute task|1|50

可以看到,日志里每两个任务的启动时间,都间隔了 50ms 左右。这个时间并不在预期中。按照设想,Quartz 应该一次性拿可用线程数个任务,然后批量提交才对。如果是批量提交到线程池,正常情况下不应有这么大的启动延迟。就算是因为 CPU 调度的原因,在这台 4C 的机器上,前四个任务的启动时间也不应有特别巨大的偏差才对。而且这台测试机为了避免干扰,除了必要的 SSH 等服务外,没有运行任何其他服务,也不存在 CPU 或内存争抢的情况。

为了确认猜想,使用相同的参数创建了相同的线程池,并使用循环批量提交任务,来测试线程池内线程的启动延迟:

ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
threadPoolTaskExecutor.setCorePoolSize(150);
threadPoolTaskExecutor.setMaxPoolSize(300);
threadPoolTaskExecutor.setQueueCapacity(150);
threadPoolTaskExecutor.initialize();

int count = 0;
while (count < 200) {
    threadPoolTaskExecutor.execute(() -> {
        log.info("Execute start at {}", System.currentTimeMillis());
        try {
            Thread.sleep(2_000);
        } catch (InterruptedException e) {
            log.error("Interrupted exception while execute task!", e);
            Thread.interrupted();
        }
        log.info("Execute end at {}", System.currentTimeMillis());
    });

    count++;
}

经过测试,得到的日志输出是这样的:

[2021-04-17 11:29:06.360][|][ThreadPoolTaskExecutor-1] Execute start
[2021-04-17 11:29:06.361][|][ThreadPoolTaskExecutor-2] Execute start
[2021-04-17 11:29:06.371][|][ThreadPoolTaskExecutor-6] Execute start
[2021-04-17 11:29:06.371][|][ThreadPoolTaskExecutor-5] Execute start
[2021-04-17 11:29:06.372][|][ThreadPoolTaskExecutor-7] Execute start
[2021-04-17 11:29:06.369][|][ThreadPoolTaskExecutor-4] Execute start
[2021-04-17 11:29:06.362][|][ThreadPoolTaskExecutor-3] Execute start
[2021-04-17 11:29:06.374][|][ThreadPoolTaskExecutor-8] Execute start
[2021-04-17 11:29:06.375][|][ThreadPoolTaskExecutor-9] Execute start
[2021-04-17 11:29:06.382][|][ThreadPoolTaskExecutor-11] Execute start
[2021-04-17 11:29:06.382][|][ThreadPoolTaskExecutor-10] Execute start
[2021-04-17 11:29:06.382][|][ThreadPoolTaskExecutor-12] Execute start
[2021-04-17 11:29:06.384][|][ThreadPoolTaskExecutor-13] Execute start
[2021-04-17 11:29:06.384][|][ThreadPoolTaskExecutor-14] Execute start
[2021-04-17 11:29:06.385][|][ThreadPoolTaskExecutor-15] Execute start
[2021-04-17 11:29:06.385][|][ThreadPoolTaskExecutor-16] Execute start
[2021-04-17 11:29:06.386][|][ThreadPoolTaskExecutor-18] Execute start
[2021-04-17 11:29:06.386][|][ThreadPoolTaskExecutor-17] Execute start
[2021-04-17 11:29:06.392][|][ThreadPoolTaskExecutor-19] Execute start
[2021-04-17 11:29:06.393][|][ThreadPoolTaskExecutor-20] Execute start
[2021-04-17 11:29:06.393][|][ThreadPoolTaskExecutor-21] Execute start
[2021-04-17 11:29:06.394][|][ThreadPoolTaskExecutor-22] Execute start
[2021-04-17 11:29:06.394][|][ThreadPoolTaskExecutor-23] Execute start
[2021-04-17 11:29:06.395][|][ThreadPoolTaskExecutor-24] Execute start
[2021-04-17 11:29:06.395][|][ThreadPoolTaskExecutor-25] Execute start
[2021-04-17 11:29:06.396][|][ThreadPoolTaskExecutor-26] Execute start
[2021-04-17 11:29:06.396][|][ThreadPoolTaskExecutor-27] Execute start
[2021-04-17 11:29:06.397][|][ThreadPoolTaskExecutor-28] Execute start
[2021-04-17 11:29:06.397][|][ThreadPoolTaskExecutor-29] Execute start
[2021-04-17 11:29:06.398][|][ThreadPoolTaskExecutor-30] Execute start
[2021-04-17 11:29:06.398][|][ThreadPoolTaskExecutor-31] Execute start
[2021-04-17 11:29:06.399][|][ThreadPoolTaskExecutor-32] Execute start
[2021-04-17 11:29:06.400][|][ThreadPoolTaskExecutor-33] Execute start
[2021-04-17 11:29:06.400][|][ThreadPoolTaskExecutor-34] Execute start
[2021-04-17 11:29:06.400][|][ThreadPoolTaskExecutor-35] Execute start
[2021-04-17 11:29:06.401][|][ThreadPoolTaskExecutor-36] Execute start
[2021-04-17 11:29:06.402][|][ThreadPoolTaskExecutor-37] Execute start
[2021-04-17 11:29:06.402][|][ThreadPoolTaskExecutor-38] Execute start
[2021-04-17 11:29:06.402][|][ThreadPoolTaskExecutor-39] Execute start
[2021-04-17 11:29:06.403][|][ThreadPoolTaskExecutor-40] Execute start
[2021-04-17 11:29:06.410][|][ThreadPoolTaskExecutor-42] Execute start
[2021-04-17 11:29:06.411][|][ThreadPoolTaskExecutor-41] Execute start
[2021-04-17 11:29:06.411][|][ThreadPoolTaskExecutor-43] Execute start
[2021-04-17 11:29:06.412][|][ThreadPoolTaskExecutor-44] Execute start
[2021-04-17 11:29:06.412][|][ThreadPoolTaskExecutor-45] Execute start
[2021-04-17 11:29:06.413][|][ThreadPoolTaskExecutor-46] Execute start
[2021-04-17 11:29:06.421][|][ThreadPoolTaskExecutor-47] Execute start
[2021-04-17 11:29:06.422][|][ThreadPoolTaskExecutor-48] Execute start
[2021-04-17 11:29:06.424][|][ThreadPoolTaskExecutor-49] Execute start
[2021-04-17 11:29:06.424][|][ThreadPoolTaskExecutor-50] Execute start

可以看到,在相同的一台四核的机器上,除了最开始启动较慢外,余下的任务启动时间的偏差基本在 1ms 内50 个任务全部启动也只用了 60ms 左右。前 150 个任务的启动时间总过也就相差 200ms 左右。这个结果表明,定时任务调度时一定还有其他耗时操作穿插其间,导致任务的提交本身存在延迟,才导致了前 50 个任务的启动时间偏差接近 3s。

深入分析

于是回到代码本身,深入分析 Quartz 的任务调度和提交逻辑。参考前面提供的 QuartzSchedulerThread 主调度线程的代码,我们可以把整个调度过程进行一个阶段划分:

  1. 等待工作线程池出现可用线程
  2. 根据可用线程数和最大批量大小从 DB 中取出将要触发的 Trigger
  3. 循环等待,直到离最近一个要出发的 Trigger 的触发时间还有 2ms
  4. 更新 DB 设置当前批次 Trigger 的触发状态
  5. 提交 Trigger 到执行线程池

其中 2 4 两步需要访问 DB 更新 Trigger 的状态,并且需要获取 TRIGGER_ACCESS 锁。按照访问 DB 的一般耗时估算,一次 DB 操作大约会消耗 5~10ms 的时间,那么这两步的 DB 操作大约每次会消耗 15~20ms 左右的时间,刚好与我们之前观察到的 50ms 的延迟接近。

可是按照正常逻辑,此处 Quartz 应该是批量去取 Trigger,应该每一批 Trigger 消耗 50ms 才是正常现象。现在每一个 Trigger 都间隔了 50ms,说明此处的批量处理一定出现了问题。于是单独深入批量拉取 Trigger 这段代码,发现之前被忽略的 maxBatchSize 有问题。由于理所当然的认为该选项的值一定会比较大,不太可能成为瓶颈,之前就没有仔细追踪这个参数。现在经过追溯,发现该值在 org.quartz.core.QuartzSchedulerResources 中存在一个默认值 1。也就是说如果没有特殊配置的话,这里的批量永远是单个拉取。这也说明了,之前的猜测是完全错误的。负载不均匀导致队列爆掉并不是因为 Quartz 批量过大导致的,而是另有原因。

尝试修复

既然找到了这个变量漏设置了值,那就修改这里的默认值,再进行测试。这里这个变量值需要修改 Quartz 的配置文件,增加 org.quartz.scheduler.batchTriggerAcquisitionMaxCount 配置项。这里修改成 50 进行测试,配合线程池的 core size 150,应该可以达到每批次处理 50 个 Trigger 的目的。修改后的日志如下:

[2021-04-17 13:45:00.051][|][threadPoolTaskExecutor-1] Execute task|1|1
[2021-04-17 13:45:00.108][|][threadPoolTaskExecutor-2] Execute task|1|2
[2021-04-17 13:45:00.173][|][threadPoolTaskExecutor-3] Execute task|1|3
[2021-04-17 13:45:00.231][|][threadPoolTaskExecutor-4] Execute task|1|4
[2021-04-17 13:45:00.288][|][threadPoolTaskExecutor-5] Execute task|1|5
[2021-04-17 13:45:00.346][|][threadPoolTaskExecutor-6] Execute task|1|6
[2021-04-17 13:45:00.403][|][threadPoolTaskExecutor-7] Execute task|1|7
[2021-04-17 13:45:00.462][|][threadPoolTaskExecutor-8] Execute task|1|8
[2021-04-17 13:45:00.518][|][threadPoolTaskExecutor-9] Execute task|1|9
[2021-04-17 13:45:00.574][|][threadPoolTaskExecutor-10] Execute task|1|10
[2021-04-17 13:45:00.629][|][threadPoolTaskExecutor-11] Execute task|1|11
[2021-04-17 13:45:00.687][|][threadPoolTaskExecutor-12] Execute task|1|12
[2021-04-17 13:45:00.741][|][threadPoolTaskExecutor-13] Execute task|1|13
[2021-04-17 13:45:00.795][|][threadPoolTaskExecutor-14] Execute task|1|14
[2021-04-17 13:45:00.849][|][threadPoolTaskExecutor-15] Execute task|1|15
[2021-04-17 13:45:00.915][|][threadPoolTaskExecutor-16] Execute task|1|16
[2021-04-17 13:45:00.971][|][threadPoolTaskExecutor-17] Execute task|1|17
[2021-04-17 13:45:01.026][|][threadPoolTaskExecutor-18] Execute task|1|18
[2021-04-17 13:45:01.081][|][threadPoolTaskExecutor-19] Execute task|1|19
[2021-04-17 13:45:01.135][|][threadPoolTaskExecutor-20] Execute task|1|20

奇怪的事情发生了,这个参数的修改完全没有起作用,Quartz 还是一个个任务调度的,而不是批量调度。同时在为了测试专门开启的调度引擎的 Debug 日志中也发现了相关日志:

[2021-04-17 13:45:00.076][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.135][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.201][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.258][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.315][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.373][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.431][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.488][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.545][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers
[2021-04-17 13:45:00.600][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 1 triggers

从这里可以看出,调度器确实每次只取了一个 Trigger 进行触发。这就很奇怪了,明明我们已经修改了最大批量值的参数,却看起来像没有生效。考虑到这里的批量值是由两个参数决定的,那么问题一定出在二者之间

  1. 线程池可用线程数有问题,获取到的数据不是设置的 150 个线程
  2. maxBatchSize 参数设置没有生效,仍然为 1

由于这两个参数在调度器之外比较用非入侵的方式检测,于是决定直接上 IDEA 用远程调试来解决:

在调度线程批量拉取 Trigger 的地方设置断点,通过查看两个变量的值,发现了问题。这里可以清晰的看到 maxBatchSize 已经变为我们设置的 50 了。但是 availThreadCount 却不是预想中的 150,而是 1。于是检查一下这个线程池:

可以看到,此处用来接收任务的线程池居然是 LocalTaskExecutorThreadPool 类型的线程池,而不是我们在配置里提供给 Quartz 的。而在初始化时提供给 Quartz 的线程池变成了该线程池内部的一个 executor。那这个线程池是哪来的呢?跟进去看下:

可以看到这个线程池是 spring 对于我们实际使用的线程池的一个封装。这个线程池内部的 taskExecutor 才是真正的由我们配置的执行任务的线程池。而这个封装中,由于内部的 executor 是不确定的,所以为了简单,此处的可用线程数查询居然永久返回 1。至此问题的根源找到了:因为 LocalTaskExecutorThreadPool 封装了我们提供给 Quartz 的线程池,且该封装在获取可用线程数时永远返回 1,导致了我们修改 maxBatchSize 没有生效。

再次深入

那么这里其实还有个问题,就是这个 LocalTaskExecutorThreadPool 是从何而来,为何没有直接使用我们构造好的 ThreadPoolTaskExecutor 呢?

经过追踪,发现这个线程池的来源在这里:

org.springframework.scheduling.quartz.SchedulerFactoryBean

可以看到,这是 Spring 对于 Quartz 初始化的一个封装。在这个封装中,如果 Spring 发现我们尝试使用自己配置的一个任务执行器的话,就会默认用 LocalTaskExecutorThreadPool 来做一个包装,除非在配置文件中配置 org.quartz.threadPool.class 显示的覆盖这个参数。而通过阅读配置,我发现这里确实是没有设置值。通过参考 Quartz 本身的初始化过程,猜测当时没有设置这个值的原因是因为 Quartz 本身默认会使用 SimpleThreadPool 来运行任务,因此考虑这个设置是多余的,于是没有进行设置。但是在考虑的过程中却忽略了 Spring 这块,导致实际的效果与预期不一致。

真相大白

至此,这里无法进行批量调度导致调度延迟的各个原因终于复出水面。在这个问题中,由于多个配置之间的互相作用最终导致了这个结果。主要有以下几点:

  1. maxBatchSize 的默认值为 1
  2. LocalTaskExecutorThreadPool 对于可用线程数永远返回 1
  3. Quartz 的默认线程池是 SimpleThreadPool,但 Spring 在使用了自定义工作线程池的情况下默认为 LocalTaskExecutorThreadPool
  4. org.quartz.threadPool.class 的默认行为与 Quartz 匹配,但与 Spring 不匹配

这里针对 3 多说几句。后面经过阅读代码,发现 Quartz 调度线程需要的 ThreadPool 并不是通常使用的 java.util.concurrent.ThreadPoolExecutor 而是 Quartz 自行封装的 org.quartz.spi.ThreadPool。因此,当我们要求 Spring 使用我们自定义的 ThreadPoolExecutor 来执行工作任务时,Spring 别无选择,必须对我们提供的 ThreadPoolExecutor 做一次封装,才能提供给 Quartz 调度线程使用。而一开始在编写代码时对这里没有深入研究则埋下了一个大坑。

因此这里的解决方案也很简单,直接去掉自定义线程池使用 Quartz 提供的 SimpleThreadPool 来处理工作负载即可。而且这里修改为 Quartz 自身的 SimpleThreadPool 来处理工作负载后,原先的调度异常的问题也自然而然的解决了。具体原因见总结。修改配置后再进行测试,看到这样的日志输出:

[2021-04-17 15:50:09.821][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 0 triggers
[2021-04-17 15:50:33.989][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 50 triggers
[2021-04-17 15:51:01.551][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 50 triggers
[2021-04-17 15:51:02.948][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 50 triggers
[2021-04-17 15:51:04.009][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 6 triggers
[2021-04-17 15:51:04.723][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 44 triggers
[2021-04-17 15:51:06.241][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 50 triggers
[2021-04-17 15:51:07.614][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 26 triggers
[2021-04-17 15:51:08.500][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 31 triggers
[2021-04-17 15:51:09.448][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 43 triggers
[2021-04-17 15:51:10.600][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 31 triggers
[2021-04-17 15:51:11.564][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 19 triggers
[2021-04-17 15:51:11.884][|][quartz-scheduler_QuartzSchedulerThread] DEBUG o.quartz.core.QuartzSchedulerThread:run:291 - batch acquisition of 0 triggers

[2021-04-17 15:51:00.810][|][quartz-scheduler_Worker-5] Execute task|1|5
[2021-04-17 15:51:00.806][|][quartz-scheduler_Worker-3] Execute task|1|3
[2021-04-17 15:51:00.810][|][quartz-scheduler_Worker-20] Execute task|1|20
[2021-04-17 15:51:00.810][|][quartz-scheduler_Worker-21] Execute task|1|21
[2021-04-17 15:51:00.813][|][quartz-scheduler_Worker-22] Execute task|1|22
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-6] Execute task|1|6
[2021-04-17 15:51:00.810][|][quartz-scheduler_Worker-9] Execute task|1|9
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-12] Execute task|1|12
[2021-04-17 15:51:00.810][|][quartz-scheduler_Worker-17] Execute task|1|17
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-13] Execute task|1|13
[2021-04-17 15:51:00.818][|][quartz-scheduler_Worker-26] Execute task|1|26
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-23] Execute task|1|23
[2021-04-17 15:51:00.809][|][quartz-scheduler_Worker-4] Execute task|1|4
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-10] Execute task|1|10
[2021-04-17 15:51:00.809][|][quartz-scheduler_Worker-18] Execute task|1|18
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-8] Execute task|1|8
[2021-04-17 15:51:00.809][|][quartz-scheduler_Worker-19] Execute task|1|19
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-14] Execute task|1|14
[2021-04-17 15:51:00.807][|][quartz-scheduler_Worker-7] Execute task|1|7
[2021-04-17 15:51:00.807][|][quartz-scheduler_Worker-16] Execute task|1|16
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-11] Execute task|1|11
[2021-04-17 15:51:00.807][|][quartz-scheduler_Worker-15] Execute task|1|15
[2021-04-17 15:51:00.814][|][quartz-scheduler_Worker-1] Execute task|1|1
[2021-04-17 15:51:00.816][|][quartz-scheduler_Worker-24] Execute task|1|24
[2021-04-17 15:51:00.806][|][quartz-scheduler_Worker-2] Execute task|1|2
[2021-04-17 15:51:00.816][|][quartz-scheduler_Worker-25] Execute task|1|25
[2021-04-17 15:51:00.827][|][quartz-scheduler_Worker-27] Execute task|1|27
[2021-04-17 15:51:00.828][|][quartz-scheduler_Worker-31] Execute task|1|31
[2021-04-17 15:51:00.828][|][quartz-scheduler_Worker-29] Execute task|1|29
[2021-04-17 15:51:00.828][|][quartz-scheduler_Worker-32] Execute task|1|32
[2021-04-17 15:51:00.829][|][quartz-scheduler_Worker-30] Execute task|1|30
[2021-04-17 15:51:00.829][|][quartz-scheduler_Worker-28] Execute task|1|28
[2021-04-17 15:51:00.830][|][quartz-scheduler_Worker-33] Execute task|1|33
[2021-04-17 15:51:00.831][|][quartz-scheduler_Worker-35] Execute task|1|35
[2021-04-17 15:51:00.829][|][quartz-scheduler_Worker-34] Execute task|1|34
[2021-04-17 15:51:00.832][|][quartz-scheduler_Worker-36] Execute task|1|36
[2021-04-17 15:51:00.834][|][quartz-scheduler_Worker-37] Execute task|1|37
[2021-04-17 15:51:00.834][|][quartz-scheduler_Worker-38] Execute task|1|38
[2021-04-17 15:51:00.836][|][quartz-scheduler_Worker-41] Execute task|1|41
[2021-04-17 15:51:00.837][|][quartz-scheduler_Worker-39] Execute task|1|39
[2021-04-17 15:51:00.837][|][quartz-scheduler_Worker-40] Execute task|1|40
[2021-04-17 15:51:00.837][|][quartz-scheduler_Worker-42] Execute task|1|42
[2021-04-17 15:51:00.838][|][quartz-scheduler_Worker-43] Execute task|1|43
[2021-04-17 15:51:00.838][|][quartz-scheduler_Worker-44] Execute task|1|44
[2021-04-17 15:51:00.839][|][quartz-scheduler_Worker-45] Execute task|1|45
[2021-04-17 15:51:00.843][|][quartz-scheduler_Worker-48] Execute task|1|48
[2021-04-17 15:51:00.843][|][quartz-scheduler_Worker-46] Execute task|1|46
[2021-04-17 15:51:00.853][|][quartz-scheduler_Worker-49] Execute task|1|49
[2021-04-17 15:51:00.857][|][quartz-scheduler_Worker-47] Execute task|1|47
[2021-04-17 15:51:00.862][|][quartz-scheduler_Worker-50] Execute task|1|50

第一段调度器的日志显示现在已经成功的使用批量的方式来进行 Trigger 的拉取了,每次拉取 50 个。在拉取了 150 个任务之后,由于线程都已在执行任务,所以只有 6 个空闲线程释放,因此拉取了 6 个任务。

第二段是实际的任务执行日志。可以看到在这段执行过程中,大约有 25 个任务在 20ms 内启动完成,50 个任务全部启动也只消耗了约 50ms 的时间,已经比原先大大提升。

同时,对于负载不均匀的问题,在修改前,三台机器的负载为:1:2:497。修改之后再次测试,变为:100:151:249。负载不均匀的问题已经基本解决。

总结

注意事项

通过这次问题排查,认识到了一些在 Quartz 搭配 Spring 使用时需要注意的问题:

  1. 尽量不要使用自定义线程池,而是使用 Quartz 实现的 SimpleThreadPool
  2. 搭配使用时,不光要留意 Quartz 本身对于配置项的默认值处理,也要注意 Spring 对于配置项的处理
  3. Quartz 的调度误差是由多方面原因造成的,需要综合考虑配置项之间的相互作用逻辑
  4. 分析问题时需要严格测试,而不能想当然的进行调整

调度异常&负载不均原因

另外再来看一下最开始遇到的调度异常&负载不均的问题。综合后续的所有分析可知,在默认情况下,Quartz 的调度逻辑是这样的:

可以看到在这个默认配置下,由于存在一个阻塞等待可用线程org.quartz.simpl.SimpleThreadPool#blockForAvailableThreads)的操作,可以保证当本机的线程全部繁忙的时候,本机的调度线程不会去获取锁,自然而然的让别的实例来接手余下的任务调度工作。同时,由于这里的阻塞等待,保证了当本机线程全忙的时候不会有任何新任务进入,也就保证了不会出现提交失败的问题。

而当使用自定义线程池的时候,调度流程变成了这样:

在这个工作模式下,阻塞等待没有了。就算自定义线程池中的线程全忙、队列已满,此处还是会返回有一个可用线程。所以此时,调度线程的工作模式就变成了,不管线程池是否爆满,始终抢夺任务并继续提交。正是因为这里没有判定线程池是否满的逻辑,导致了最初的提交失败。而且由于不再等待可用线程,这里的循环变成了 加锁->拉 Trigger->提交 的循环,从而导致最初最先启动的线程在抢锁的过程中有极大的优势(没抢到锁会强制等待,而等待的时候锁已经又被最先启动的线程抢了),从而导致负载的严重失衡。

所以为了解决提交失败和负载不均的问题,最简单的方法是不要使用自定义线程池,而是通过 org.quartz.threadPool.class 设置使用 SimpleThreadPool,并根据机器负载调节线程数量。如果一定要使用自定义线程池的话,则必须实现 Quartz 提供的 org.quartz.spi.ThreadPool 接口,并实现阻塞等待可用线程的逻辑。千万不能直接使用 Spring 提供的 LocalTaskExecutorThreadPool

调度延迟产生的原因

根据本次分析的过程可以看出,Quartz 的调度延迟主要由以下几个方面组成:

  1. 同步加锁延迟。当 Quartz 使用DB作为集群持久化存储的场景下,为了保证调度秩序,避免重复调度或漏调度,每一次 DB 操作都要进行加锁。而每次调度时,需要先从 DB 读取要触发的 Trigger 信息并更新状态为 ACQUIRED,然后在将要触发时更新状态到 EXECUTING,之后才会向工作线程池提交任务。虽然在读取 Trigger 信息的时候大部分操作都不是批量进行的,但是加锁操作是针对一批任务的。考虑到正常的 DB 读写耗时在 5~10ms 左右,如果不进行批量操作的话,按照 50 个任务一批计算,每一批的加锁时间就白白增加了 250~500ms。因此,进行批量拉取可以有效的减小 DB 加锁操作带来的调度延迟。同时,考虑到锁的竞争会导致线程等待,批量加锁操作还可以有效的降低锁争抢,提升整体效率。如果业务场景对调度延迟比较敏感,应考虑使用性能更好的独立 DB 实例,并尽量降低 Quartz 实例到 DB 之间的网络延迟;
  2. 批量执行排队延迟。如果同时触发的任务数量超过了总集群的线程池上限,则一定会被分为多个批次进行触发,这时就会出现排队延迟。这里每个批次间的排队延迟将取决于任务的执行速度。单个任务执行的越慢则越靠后被触发的批次延迟越大。当总线程数耗尽时,下一次调度一定会等到有线程释放才会开始。理想情况下所有任务都应在一个批次内做完。因此应根据工作负载的情况,对 Quartz 集群进行扩容,增加总线程数,来避免任务进入排队。但是由于成本限制,这个方式往往很难实施。而且在实际使用的过程中,偶尔会出现任务本身的执行耗时不可控的情况。因此在实际使用的过程中,需要根据实际的业务情况,合理调节批量参数和工作线程数。当然在调节工作线程数量时还需要需要考虑到机器实际的负载能力,不能无谓的提高,反而导致负载不均衡的情况出现。同时应当考虑采取异步机制,并通过消息队列等异步化手段,将任务快速分发下去。再结合快速扩容机制,在峰值来临前对执行器进行扩容,来进一步降低延迟。这里推荐异步化任务执行器而不是大量扩容 Quartz 集群的主要原因在于,Quartz 集群本身是一个有状态的集群,相对来说逻辑复杂任务较重,且存在集群锁,不适合进行快速扩缩容。而在需要大批量调度的场景下,我们的工作负载往往都是无状态逻辑简单轻量化的小任务。这种任务最适合配合 K8S 等集群进行快速扩容支撑峰值,并在谷时缩容降低成本;
  3. CPU调度延迟。当调度线程将任务提交给工作线程池后,工作线程池中的线程最终还需要依赖 CPU 时间片来执行,若调度机器的 CPU 负载较高,或线程池数量不合理,那么线程在真正被 CPU 执行前将会有较大等待。为了尽量减少这里的执行延迟,应将工作线程池部署在 CPU 核数较多且负载不高的机器上。同时应该合理设置工作线程数量,避免一次性触发过多任务。

PHP加解密算法使用 openssl 替换 mcrypt 扩展的一个小坑

由于 PHP 7.2 不再支持 mcrypt,因此需要将 mcrypt 替换为 openssl。

但是在替换发现,php 的 openssl 和 mcrypt 实现有一些不同,有几个坑需要注意。

  1. mcrypt 中的 RIJNDAEL_128 算法是 AES 算法的超集,RIJNDAEL_128 的 128 指的是 Block Size,而 AES-128 中的 128 是 Key Size。因此,同是 RIJNDAEL_128 算法,如果你使用的 Key 是 128 位的(16 个字符)那就等同 AES-128。如果 Key 是 192 位的(24 个字符),那就等同与 AES-192。如果 Key 是 256 位的(32 个字符),则等同与 AES-256
  2. 如果使用 RIJNDAEL_256,则无法对应到 AES 算法。因为 AES 固定了 Block Size 是 128,没有 256 的选择
  3. php 的 openssl 实现的 AES 算法,只有 PKCS#7 padding 和 no padding 两个选择,而 mcrypt 默认是 zero padding。因此,如果原先没有手动处理 padding,则切换到 openssl 的时候需要启用 no padding 并手动处理 padding。
  4. 一些函数的替换:mcrypt_get_iv_size  替换为 openssl_cipher_iv_lengthmcrypt_create_iv  替换为 openssl_random_pseudo_bytes

修改前后代码如下:

<?php
define('ENCRYPT_METHOD', 'AES-256-CBC');
define('IV_SIZE', openssl_cipher_iv_length(ENCRYPT_METHOD));

function encrypt_mcrypt($payload, $key)
{
  // 初始化 IV
  $iv = openssl_random_pseudo_bytes(IV_SIZE);
  // 调用加密
  $crypt = mcrypt_encrypt(MCRYPT_RIJNDAEL_128, $key, $payload, MCRYPT_MODE_CBC, $iv);
  // 拼接 IV 和 密文
  $combo = $iv . $crypt;
  // 编码拼接后的密文
  $garble = base64_encode($combo);
  return $garble;
}

function decrypt_mcrypt($garble, $key)
{
  // 解码密文
  $combo = base64_decode($garble);
  // 根据 IV SIZE 提取 IV
  $iv = substr($combo, 0, IV_SIZE);
  // 获取剩余密文
  $crypt = substr($combo, IV_SIZE);
  // 解密
  $payload = mcrypt_decrypt(MCRYPT_RIJNDAEL_128, $key, $crypt, MCRYPT_MODE_CBC, $iv);
  return $payload;
}

function encrypt_openssl($payload, $key)
{
  // 初始化 IV
  $iv = openssl_random_pseudo_bytes(IV_SIZE);
  // 对密文进行 padding, 16 = 128 / 8
  if (strlen($payload) % 16) {
    $payload = str_pad(
      $payload,
      strlen($payload) + 16 - strlen($payload) % 16,
      "\0"
    );
  }
  // 加密
  $encryptedMessage = openssl_encrypt($payload, ENCRYPT_METHOD, $key, OPENSSL_RAW_DATA | OPENSSL_NO_PADDING, $iv);
  // 编码,拼接 IV
  return base64_encode($iv . $encryptedMessage);
}
function decrypt_openssl($garble, $key)
{
  // 解码密文
  $raw = base64_decode($garble);
  // 根据 IV SIZE 提取 IV
  $iv = substr($raw, 0, IV_SIZE);
  // 获取剩余密文
  $data = substr($raw, IV_SIZE);
  // 解密
  return openssl_decrypt($data, ENCRYPT_METHOD, $key, OPENSSL_RAW_DATA | OPENSSL_NO_PADDING, $iv);
}

$key = md5("password");
echo (decrypt_openssl(encrypt_mcrypt("4db8c44de8f16b4f0c39ef3b38d47c6bdd000082b3b628ee25c20b308d02cf29", $key), $key) . "\n");
echo (decrypt_mcrypt(encrypt_openssl("4db8c44de8f16b4f0c39ef3b38d47c6bdd000082b3b628ee25c20b308d02cf29", $key), $key) . "\n");

 

AWS Lightsail 修改 DB 参数

AWS 推出的 Lightsail Database 是目前比较实惠的托管 DB 方案。不过相对来说,Lightsail 的控制面板功能较少,很多参数无法修改。经过搜索发现,其实我们有很多参数可以调,只是需要通过命令行的方式来调整。

准备工作

安装 aws-cli 工具

https://aws.amazon.com/cli/

https://lightsail.aws.amazon.com/ls/docs/en_us/articles/lightsail-how-to-set-up-and-configure-aws-cli

Linux:

sudo apt-get install awscli

MacOS:

brew install awscli

Python(通用):

pip install awscli

设置 Access Key

https://lightsail.aws.amazon.com/ls/docs/en_us/articles/lightsail-how-to-set-up-access-keys-to-use-sdk-api-cli

先在 AWS 控制台新建用户或 Key:

https://console.aws.amazon.com/iam/home#/users

然后执行:

aws configure

按照提示依次输入:

AWS Access Key ID 控制台中创建的 Key
AWS Secret Access Key 控制台中创建的 Key 对于的 Secret
Default region name 可用区,https://docs.aws.amazon.com/AmazonRDS/latest/UserGuide/Concepts.RegionsAndAvailabilityZones.html
Default output format 输出格式,建议 json

获取现有设置

aws lightsail get-relational-database-parameters --relational-database-name DatabaseName > current_params.json

注意 DatabaseName 替换为创建 DB 时设置的名称。就是 Lightsail 控制面板里显示的那个。

执行成功后打开 json 文件,可以看到所有变量。

注意每个变量有几个属性:

Allowed values 允许的变量范围
Apply method 变量的生效时间。immediate 表示立即生效,pending-reboot 表示重启后生效
Apply type 底层引擎支持的生效方式。dynamic 动态,可以立即生效,static 静态,必须重启后才能生效
Data type 数据类型
Description 变量描述
Is modifiable 能否修改
Parameter name 变量名

这里我们用最大连接数举例:

{
    "allowedValues": "1-100000",
    "applyMethod": "pending-reboot",
    "applyType": "dynamic",
    "dataType": "integer",
    "description": "The number of simultaneous client connections allowed.",
    "isModifiable": true,
    "parameterName": "max_connections",
    "parameterValue": "{DBInstanceClassMemory/12582880}"
}

可以看到,最大连接数是一个动态变量,整型,可修改。默认是实例内存大小/12582880,也就是 1G 内存约 80 个链接。实际比这个数值少,没有具体深究。

修改设置

找到了对于的参数,就可以修改了。修改参数使用的指令是:

aws lightsail update-relational-database-parameters --relational-database-name DatabaseName --parameters "parameterName=ParameterName,parameterValue=NewParameterValue,applyMethod=ApplyMethod"

DatabaseName 是实例名,ParameterName 替换为要修改的变量,NewParameterValue 替换为变量的值,ApplyMethod 替换为想要的生效方式。

比如,我们修改最大连接数到 1000,重启后生效,对应的命令为:

aws lightsail update-relational-database-parameters --relational-database-name DatabaseName --parameters "parameterName=max_connections,parameterValue=1000,applyMethod=pending-reboot"

成功后会收到这样的响应:

{
    "operations": [
        {
            "id": "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
            "resourceName": "DatabaseName",
            "resourceType": "RelationalDatabase",
            "createdAt": 1570000000.000,
            "location": {
                "availabilityZone": "ap-northeast-1a",
                "regionName": "ap-northeast-1"
            },
            "isTerminal": true,
            "operationDetails": "",
            "operationType": "UpdateRelationalDatabaseParameters",
            "status": "Succeeded",
            "statusChangedAt": 1570000000.000
        }
    ]
}

看到 status Succeeded 就是设置成功啦!

官方文档:

https://lightsail.aws.amazon.com/ls/docs/en_us/articles/amazon-lightsail-updating-database-parameters

 

各家云上 Kubernetes 服务对比

最近在研究 GitLab 的 DevOps 工作流,看到 GitLab 可以和 K8s 通过 API 进行交互,于是决定研究一下各种云的 K8s 服务,做一个简单的对比。

部署方式

根据部署方式的不同,我们可以将不同的云服务进行分类:

  • 全托管:Master 节点和 Worker 节点完全由云来管理,只提供 API 来调用,一般按照实际的 CPU 和内存使用来计费
  • 半托管:Master 节点由云来管理,自行购买 Worker 节点。可以修改部分 Master 节点的配置,所有容器在自己的机器上运行
  • 全独立:Master 节点和 Worker 节点都由用户管理,云只负责节点的初始化和小部分维护工作。可以修改几乎所有 Master 的配置,整个集群完全独立

首先来看下各个云提供商所提供的服务类型:

提供商\类型 全托管 半托管 全独立
腾讯云 CIS TKE TKE 独立部署
阿里云 Serverless Kubernetes Kubernetes 托管版 Kubernetes
Azure 容器实例 Kubernetes 服务 /
AWS ECS EKS /
GCP / GKE GKE On-Prem
仅能在非 GCE 机器部署

其中,全托管模式只有阿里云提供 k8s API 调用,其余提供商都不直接支持 k8s API

半托管模式基本相似,都是由云服务商运行 Master Node,区别在于 AWS 的 EKS 对 Master 节点收费,其余服务商均不收取 Master 节点的费用。

版本支持

然后再来看看各个服务商对于 k8s 版本的支持:

提供商\版本 最低版本 最高版本 是否支持升级
腾讯云 1.8.13 1.12.4
阿里云 1.11.5 1.12.6
Azure 1.10.12 1.14.0
AWS 1.10 1.12
GCP 1.11.10 1.13.6

可以看到,除了 Azure 对于新版的支持非常激进外,大部分云提供商都很谨慎的对版本升级进行跟进。GCP 是个例外,毕竟 K8s 是 Google 搞出来的,似乎比所有人都更激进。

价格

最后再来看看各个服务商的价格:

提供商\版本 Master 节点 常驻 Worker 突发 Worker
腾讯云 / ¥49.5/m 同 ECS
阿里云 / 至少两个
2c4G
$57.41/m
¥396.129/m
Azure / 至少一个
2c4G
$49.18/m
¥339.342/m
同普通虚拟机
AWS $0.20/hr
¥1.38/hr
¥993.6/m
/ 同 ECS
GCP / 1c1.7G
$13.8/m
¥95.22/m
同 GCS
$0.031611 / vCPU hour
$0.004237 / GB hour
按秒计费,最低 1 分钟

1美元按6.9人民币计算

总体来说,如果是不常用的集群,节点费用上 GCP 较低,AWS 则由于 Master 管理费的存在很不划算。

而阿里云则是比较奇葩,基础版本的机型无法使用。内存 CPU 较小的机型则不能使用阿里定制的网络插件。而且,阿里云是唯一一个必须至少有 2 个常驻节点的服务商。所以整体来说成本较高。

总结

对于短时间使用的测试集群,腾讯云是一个不错的选择。整体价格低廉,成本低。GCP 也非常不错,就算是长时间闲置也不会有太高的花费。

对于生产集群,考虑服务稳定性和后续的持续维护性,Azure 和 GCP 都是不错的选择。Azure 价格略高,但是相对来说周边生态较好。GCP 则费用低廉。如果对 Azure 周边生态有所依赖的,可以尝试一下。而对于个人开发者来说,由于 GCP 还有免费额度,可能是初期一个较好的选择。

MySQL 分区表的一些问题

最近在使用 MySQL 分区表的时候,研究了一下多列 Range 分区,也就是

PARTITION BY RANGE COLUMNS(`a`, `b`, `c`) (
    PARTITION p1 VALUES LESS THAN (0, 0, MAXVALUE),
    PARTITION p2 VALUES LESS THAN (10, 10, MAXVALUE),
    PARTITION p3 VALUES LESS THAN (20, 20, MAXVALUE)
)

在多列的情况下,MySQL 的分区策略和单列略有不同,这也是比较坑的地方,查遍所有文档都没人提到。。。

先说说单列 Range 分区。比如,如果这么写:

PARTITION BY RANGE(`a`) (
    PARTITION p1 VALUES LESS THAN (0),
    PARTITION p2 VALUES LESS THAN (10),
    PARTITION p3 VALUES LESS THAN (20)
)

那么,p1 中的数据是 a 值小于 0 的,注意,是小于,不包括 0 。然后,p2 中的数据是 a 值在 [0, 10) 之间的,注意右边是开区间,不包括 10 。同样的,p3 中的数据是 a 值在 [10, 20) 之间的,不包括 20 。

也就是说,如果有这么一条数据:

INSERT INTO test_table (`a`, `b`, `c`) VALUES (10,10,20);

由于 a=10,所以会落入 p3 分区。

再来看多列分区,使用第一个多列分区语句,执行 INSERT,会发现,数据插入到了 p2 分区,而不是想象中的 p3 分区。

这里么的原因,就涉及到 MySQL 内部的比较了。当使用单列分区时,MySQL 的比较方法是:

if a < 0  then p1
if a < 10 then p2
if a < 20 then p3

当采用多列分区的时候,比较方法就相应的变成了:

if (a,b,c) < (0 , 0 , MAXVALUE) then p1
if (a,b,c) < (10, 10, MAXVALUE) then p2
if (a,b,c) < (20, 20, MAXVALUE) then p3

那咱们再来看看直接执行这个比较会怎么样:

mysql> SELECT 10 < 10;
+---------+
| 10 < 10 |
+---------+
|       0 |
+---------+
1 row in set (0.01 sec)

mysql> SELECT 9 < 10;
+--------+
| 9 < 10 |
+--------+
|      1 |
+--------+
1 row in set (0.01 sec)

mysql> SELECT (10,10) < (10,10);
+-------------------+
| (10,10) < (10,10) |
+-------------------+
|                 0 |
+-------------------+
1 row in set (0.00 sec)

mysql> SELECT (10,9) < (10,10);
+------------------+
| (10,9) < (10,10) |
+------------------+
|                1 |
+------------------+
1 row in set (0.00 sec)

惊喜来了!(10,10) < (10,10) 毫不意外的被判定为 false ,但是 (10,9) < (10,10) 确是 true 的!

再来一些尝试:

mysql> SELECT (11,9) < (10,10);
+------------------+
| (11,9) < (10,10) |
+------------------+
|                0 |
+------------------+
1 row in set (0.00 sec)

mysql> SELECT (9,11) < (10,10);
+------------------+
| (9,11) < (10,10) |
+------------------+
|                1 |
+------------------+
1 row in set (0.01 sec)

mysql> SELECT (9,10) < (10,10);
+------------------+
| (9,10) < (10,10) |
+------------------+
|                1 |
+------------------+
1 row in set (0.01 sec)

惊呆了,(9,11) < (10,10) 居然也是 true !

来,实际测试一下:

CREATE TABLE `test_table` (
    `a` INT(20) NOT NULL,
    `b` INT(11) NOT NULL
) ENGINE=INNODB DEFAULT CHARSET=UTF8MB4
PARTITION BY RANGE COLUMNS(`a`, `b`) (
    PARTITION p1 VALUES LESS THAN (0, 0),
    PARTITION p2 VALUES LESS THAN (10, 10),
    PARTITION p3 VALUES LESS THAN (20, 20)
);

INSERT INTO `test_table` VALUES (10,10);
INSERT INTO `test_table` VALUES (10,9);
INSERT INTO `test_table` VALUES (9,11);

执行之后发现,第一条记录毫不意外的在 p3 ,但是第二条记录和第三条记录却都在 p2 !

那么这时候执行查询会发生什么呢?

mysql> SELECT * FROM `test_table`;
+----+----+
| a  | b  |
+----+----+
| 10 |  9 |
|  9 | 11 |
| 10 | 10 |
+----+----+
3 rows in set (0.00 sec)

mysql> EXPLAIN PARTITIONS SELECT * FROM `test_table` WHERE a=10;
+------+-------------+------------+------------+------+---------------+------+---------+------+------+-------------+
| id   | select_type | table      | partitions | type | possible_keys | key  | key_len | ref  | rows | Extra       |
+------+-------------+------------+------------+------+---------------+------+---------+------+------+-------------+
|    1 | SIMPLE      | test_table | p2,p3      | ALL  | NULL          | NULL | NULL    | NULL |    3 | Using where |
+------+-------------+------------+------------+------+---------------+------+---------+------+------+-------------+
1 row in set (0.00 sec)

mysql> EXPLAIN PARTITIONS SELECT * FROM `test_table` WHERE b=10;
+------+-------------+------------+------------+------+---------------+------+---------+------+------+-------------+
| id   | select_type | table      | partitions | type | possible_keys | key  | key_len | ref  | rows | Extra       |
+------+-------------+------------+------------+------+---------------+------+---------+------+------+-------------+
|    1 | SIMPLE      | test_table | p1,p2,p3   | ALL  | NULL          | NULL | NULL    | NULL |    5 | Using where |
+------+-------------+------------+------------+------+---------------+------+---------+------+------+-------------+
1 row in set (0.00 sec)

可以看到,当我们使用多列中的第一列做查询时,MySQL 会识别出 p1 分区一定没有数据,所以优化中直接去掉了这个分区,但是搜索了 p2 p3 两个分区。

这也是疑惑点之一,按照 MySQL 的规则,似乎 p2 也一定不会有数据,为啥要搜 p2

再来看下面一个查 b 的语句,会发现根本没有用分区,直接全分区搜索。。。看来 MySQL 也知道可能有一些 b 值并不是存在相应的分区中,需要全表扫描。

具体原因可能需要深入分析 MySQL 源码,这里就先说这么一个需要注意的现象,防止踩坑。。。

nginx rewrite 的一个小坑

今天在配置 Nginx 的时候写了这么一个 location

location /a {
    rewrite /a/(.*) /$1 break;
    ...
}

然后发现当我直接访问 /a 的时候,rewrite 并没有生效,后端收到的还是 /a 而不是我想象中的 / 。想了想可能是结尾 / 的问题,于是这样改:

location /a {
    rewrite /a(.*) $1 break;
    ...
}

结果新的问题来了,由于这样匹配到的 $1 是空的,所以 Nginx 报错了,the rewritten URI has a zero length

所以这种情况下只好这么写:

location /a/ {
    rewrite /a(.*) $1 break;
    ...
}

注意第一行的末尾 / 。这种情况下,访问 /a 会被 Nginx 自动重定向到 /a/ ,然后重写之后的 uri 就是 /,问题解决。