记一次时区异常问题排查思路和过程

shabbywu大约 5 分钟

背景介绍

最近有用户反馈线上运行的 nodejs 应用时区信息不对, 拿到的时间是 UTC 时区的时间。

> Date()
Fri Aug 11 2023 06:26:02 GMT+0000 (Coordinated Universal Time)

登录容器后排查，发现容器内的时区应该是东八区，不应该获取到 UTC 时区的时间。

❯ date
Fri Aug 11 14:23:51 CST 2023

使用 python 交叉验证时区信息均是东八区。

>>> import datetime
>>> datetime.datetime.now()
datetime.datetime(2023, 8, 11, 14, 27, 42, 544771)

通过交叉验证暂时可以判断是 nodejs 获取时区的逻辑与 linux date 命令和 python datetime.now() 函数不一致
所以需要先确认 nodejs 获取时区的逻辑，nodejs 的源码可以在 nodejs/nodeopen in new window 项目中找到。

通过查阅 nodejs 的源码, 可以追踪到 nodejs 的时区选择是基于 ICU, International Components for Unicodeopen in new window(一个跨平台的字符和时间处理库), 而 python 的 datetime.datetime.now() 是通过 c 语言的 localtime_ropen in new window 获取系统时间。

显然，目前可以判断时区错误是 ICU 算法与 localtime_r 的行为不一致导致的。

因此需要再次深入 ICU 的算法排查, 以下是 ICU 时区探测主入口 TimeZone::detectHostTimeZoneopen in new window 的部分代码摘录。

TimeZone* U_EXPORT2
TimeZone::detectHostTimeZone()
{
    ...
    // Get the timezone ID from the host.  This function should do
    // any required host-specific remapping; e.g., on Windows this
    // function maps the Windows Time Zone name to an ICU timezone ID.
    hostID = uprv_tzname(0);

    UnicodeString hostStrID(hostID, -1, US_INV);

    hostZone = createSystemTimeZone(hostStrID);
    ...
}

显而易见, 时区探测的实现在 uprv_timezoneopen in new window

uprv_timezone 实现十分复杂, 有大量的 if-else 分支, 以下是摘取出来的有效代码。

U_CAPI const char* U_EXPORT2
uprv_tzname(int n)
{
    // 获取软链指向的真实路径, 结果存在 gTimeZoneBuffer
    // TZDEFAULT = "/etc/localtime"
    char *ret = realpath(TZDEFAULT, gTimeZoneBuffer);
    if (ret != nullptr && uprv_strcmp(TZDEFAULT, gTimeZoneBuffer) != 0) {
        // TZZONEINFOTAIL = "/zoneinfo/"
        int32_t tzZoneInfoTailLen = uprv_strlen(TZZONEINFOTAIL);
        // uprv_strstr 返回 TZZONEINFOTAIL 在 gTimeZoneBuffer 的起始位置
        const char *tzZoneInfoTailPtr = uprv_strstr(gTimeZoneBuffer, TZZONEINFOTAIL);
        if (tzZoneInfoTailPtr != nullptr) {
            tzZoneInfoTailPtr += tzZoneInfoTailLen;
            // 判断 /zoneinfo/ 后面的子串是否 Olson ID
            if (isValidOlsonID(tzZoneInfoTailPtr)) {
                return (gTimeZoneBufferPtr = tzZoneInfoTailPtr);
            }
        }
    }
    ...
}

终于排查到关键路径, 以上代码判断的核心逻辑是: 如果 /etc/localtime 是一个符号链接, 且链接指向的路径符合 Olson ID 的规则, 那么将会使用该 Olson ID 代表的时区, 否则将直接返回字符串, 代表未设置时区。

延伸阅读: 什么是 Olson Time Zone IDs

Olson ID（Olson Time Zone ID）是一个用于标识世界各个时区的唯一标识符。它通常以字符串的形式表示，例如："America/New_York"、"Europe/London" 等。这些标识符是由 "Olson Time Zone Database"（也称为 "tz database" 或 "IANA Time Zone Database"）维护和分发的。

完整的 Olson Time Zone IDsopen in new window 列表看通过链接查看。

重回案发现场

通过查阅源码终于找到了问题的蛛丝马迹, 接下来我们重新返回案发现场确认导致 Bug 的真正原因。

root@******:~## ls -lah /etc/localtime
lrwxrwxrwx 1 root root 27 Apr 21  2020 /etc/localtime -> /usr/share/zoneinfo/Etc/UTC

可以看到, /etc/localtime 的确是符号链接, 且链接的路径对应的是 Etc/UTC。但 Etc/UTC 并非 Olson ID, 因此 nodejs 无法正常判断系统的时区, 最后使用了 UTC 时区作为缺省值。

修复方式也很简单，只需要将 /etc/localtime 的符号链接指向代表东八区的 Olson ID 文件即可。

## 修复软连
root@******:~## rm /etc/localtime
root@******:~## ln -s /usr/share/zoneinfo/Asia/Shanghai /etc/localtime
## 验证修复
root@******:~## ls -lah /etc/localtime
lrwxrwxrwx 1 root root 27 Apr 21  2020 /etc/localtime -> /usr/share/zoneinfo/Asia/Shanghai

## nodejs 里执行
> Date()
Fri Aug 11 2023 14:46:22 GMT+0800 (China Standard Time)

到此, 我们终于排查出 nodejs 获取到错误时区的原因是因为未正确设置 /etc/localtime 链接的路径。

但令人费解的事情出现了, 明明 /etc/localtime 指向的是 /usr/share/zoneinfo/Etc/UTC, 为什么操作系统和 python 都认为是东八区呢？

案中案

显然问题不是那么简单, 我们再次将目光移到 python 时间的底层实现 localtime_ropen in new window 身上。 localtime_r 依赖 tzset 函数设置时区, 以下是 tzset 的注释(部分摘要)的翻译。

Linux man page - tzset(3)

tzset() 函数从环境变量 TZ 初始化 tzname 变量。
如果环境变量 TZ 不存在，tzname 变量将被初始化为本地时间的最佳近似值，该值由系统时区目录中的 tzfile(5) 格式文件 localtime 指定。(通常是 /etc/localtime)

我们不妨看下案发现场中, /etc/localtime 的内容究竟是什么。

root@******:~## cat /etc/localtime
TZif2
     �Y^��      �p�ӽ����|@�;>�Ӌ{��B���E"�L���<��fp���A|��R i�� ~��!I}�"g� #)_�$G� %|&'e &�^(G (�@q�~�pLMTCDTCSTTZif2
                                                                                                                    �����~6C)�����Y^������ �p�����ӽ������������|@�����;>�����Ӌ{������B�������E"�����L�������<������fp�����������A|��R i�� ~��!I}�"g� #)_�$G� %|&'e &�^(G (�@q�~�pLMTCDTCST
CST-8

虽然文件有一堆乱码, 但我们可以很清晰看到 /etc/localtime 指向的 /usr/share/zoneinfo/Etc/UTC 文件记录的时区是 CST-8, 也就是东八区。

所以, 这个奇怪的案发现场是虽然 /etc/localtime 软链指向了 /usr/share/zoneinfo/Etc/UTC, 但实际上 /usr/share/zoneinfo/Etc/UTC 的内容是 Asia/Shanghai。

通过 md5sum 计算的摘要进一步确认问题的确如此。

root@******:~## md5sum /usr/share/zoneinfo/Etc/UTC
1d458654143678b18662d1b5b4b5de9d  /usr/share/zoneinfo/Etc/UTC
root@******:~## md5sum /usr/share/zoneinfo/Asia/Shanghai 
1d458654143678b18662d1b5b4b5de9d  /usr/share/zoneinfo/Asia/Shanghai

符号链接引发的乌龙事件

终于追查时区问题的根源 - /usr/share/zoneinfo/Etc/UTC 被意外覆盖了。
但是谁会闲着无事将 Asia/Shanghai 的内容覆盖到 Etc/UTC 呢？显然这不是正常行为。
带着最后的疑问我翻查了这个容器镜像的 Dockerfile

FROM heroku/heroku:18.v27
...
## 设置时区
RUN cp /usr/share/zoneinfo/Asia/Shanghai /etc/localtime

...

如上所示, 这个容器镜像通过将 /usr/share/zoneinfo/Asia/Shanghai 复制到 /etc/localtime 来设置市区。
但很不巧, /etc/localtime 是一个符号链接, 因此这个操作实际上是将 /usr/share/zoneinfo/Asia/Shanghai 复制到了 /usr/share/zoneinfo/Etc/UTC。

总结

往往隐藏很深的问题, 根本原因就是这么简单 -- 符号链接本质是一个指向另一个文件或目录的路径引用。
当访问符号链接时，操作系统会根据路径引用跳转到链接指向的实际文件。

设置时区需谨慎, 最通用的方案是设置 TZ 环境变量。
容器内覆盖文件需谨慎, 避免遇到符号链接导致出现预期外的行为。
使用符号链接需谨慎，读写符号链接实际上操作的是引用的

记一次时区异常问题排查思路和过程

记一次时区异常问题排查思路和过程

背景介绍

排查历程

深入源码分析

重回案发现场

案中案

符号链接引发的乌龙事件

总结