写在前面
Sqlldr 是 Oracle 用于将数据从外部文件直接导入到 Oracle 数据库表的工具。
笔者负责的公司项目中，某一个业务需要通过 sqlldr 导入外系统给出的数据。在日常测试和客户反馈中，碰到了 sqlldr 导入数据缓慢的问题。经过排查，处理了两个原因导致的性能问题。
在排查过程中，使用的工具是系统调用追踪工具 strace，本文将记录两次排查过程。
网络导致的问题
公司测试环境
第一次碰到 sqlldr 加载数据慢的问题，是测试同事反馈的。当时测试同事反馈该业务执行非常缓慢，在查看了业务日志后，发现时间卡在了 sqlldr 导入数据的阶段。业务中有将近一百五十张表，每张表的导入时间以分钟计时。
排查时，首先查看了 sqlldr 的导入日志，发现实际的数据导入时间都是秒级的，与日志显示的分钟级不符。于是手动执行了 sqlldr 相关的导入命令，将一张表的数据手动导入。通过 time 命令计时和肉眼观察，发现虽然整个 sqlldr 命令完成耗时一分钟多，但是耗时都是在连接数据库的阶段，一旦连接成功，数据在一秒内就可以完成导入。
于是将目光放在了网络相关的问题。一开始还不知道应当如何排查网络问题，但是突然想到可以使用 strace 追踪系统调用，看一看耗时都在哪里。于是通过以下命令抓取了追踪日志。
1 | strace -T -tt -f -o strace.log sqlldr database control=table.CTL |
这条命令将追踪 sqlldr 执行过程中，父进程及其子进程的每个系统调用的耗时，并打印到日志文件中。并通过以下命令将其中耗时大于 0.1 s 的系统调用都打印出来。
1 | grep -E '<(0\.[1-9][0-9]*|[1-9][0-9]*\.[0-9]+|[1-9][0-9]*\.0[1-9][0-9]*)>' strace.log |
由于当时排查时的日志没有保留，且后续没能构建同样的问题环境，就不拿出具体的日志了。
总之，日志显示，耗时大头都在一些读写相关的系统调用上，向上追踪文件描述符，发现这是一个 socket 链接，其 connect 的 IP 地址指向了公司的 AD 域服务器。与 IT 同事联系，发现这台服务器未启动。启动后，业务就正常运行，数据导入时间恢复预期。
客户生产环境
后来某家客户联系到开发组，反馈了该业务执行缓慢的问题，开发组同事查看日志后发现也是 sqlldr 导入数据慢的问题。笔者在听说了这个事情后，立刻联想到了当初排查公司测试环境的事情。于是主动介入排查，在执行了相同的排查流程后，得到追踪日志。
拿到追踪日志分析时，发现同样是读写系统调用的耗时问题，向上追踪文件描述符，发现socket链接 connect 的 IP 地址是 8.8.8.8，立刻反应过来这是 Google 的 DNS 服务。查看了客户服务器的 DNS 配置，配置文件中的确配置的是此 IP。
于是拿着追踪日志与客户沟通，向对方解释了 sqlldr 导入数据缓慢的原因，并建议对方配置国内云服务商的 DNS 服务器。客户在修改配置后，重新执行业务，发现执行时间恢复正常。
sqlldr bug 导致的问题
在后来的开发自测过程中，笔者发现在开发服务器上测试该业务时，也有导入数据缓慢的问题，基于经验怀疑是网络问题。
测试环境上数据量较小，正常情况下每张表的导入时间不会超过 500 毫秒。但是查看业务日志时发现，每张表的导入时间都在 1 秒左右。执行了排查流程后，发现并不是网络问题，而是另一个系统调用耗时。
1 | 32176 18:01:51.382432 nanosleep({tv_sec=1, tv_nsec=0}, <unfinished ...> |
可以看到，进程32176调用了 nanosleep()，传入参数为 1秒。而这个进程也是由加载了sqlldr的进程 clone() 出来的，且这个进程的功能似乎很简单，就是单纯的 sleep。
1 | 32176 18:01:51.382305 set_robust_list(0x7fbc34a989a0, 24) = 0 <0.000072> |
很奇怪的是，这个问题只在 Oracle database 19.3.0.0.0 的 database 和 sqlldr 上才有问题。笔者另一台装有 Oracle database 12.2.0.1.0 的环境，使用 sqlldr 就没有这个问题。且只有 19.3 的 sqlldr 向 19.3 的 database 中导入数据才有问题，两种版本交叉使用则没有问题。
当时笔者排查到这里后，没有思路，且 Google 也没有线索，于是暂时搁置下来。
前几天开发组的同事又碰到客户反馈这个业务的执行耗时问题，笔者提醒了同事可能是网络问题，同事也想起当时的排查。于是在客户环境上执行排查流程拿到追踪日志后，发现是 nanosleep() 的耗时问题，笔者立刻想到了公司测试环境上碰到过的事情，于是和同事沟通了这个问题，也和同事在公司测试环境上进行了复现。
这位同事对 Oracle database 的研究颇为深入，在听说笔者反馈的版本问题后，立刻着手下载了不同版本的 sqlldr，最终发现 19.14.0.0.0 的 sqlldr 在导入数据时没有问题。这位同事也很有钻研精神，在 Oracle support 上检索了一天，最终找到了相关的 Bug 记录：「Bug 30571037 : 19C SQL*PLUS TAKES 1 SECOND WHEN EXITING AN APPLICATION」。
同样是 nanosleep() 的耗时问题，同样是 1 秒。在 Google 这个 Bug 后，找到了这篇文档，里面提到了一个参数导致的客户端退出缓慢的问题，并指出可以关闭这个参数来规避这个问题。
在客户环境上关闭这个参数后，sqlldr 导入数据缓慢的问题得到了解决。
写在最后
实际上，笔者对于 Oracle database 并没有太多了解，更多的是写业务 SQL。在第一次碰到 sqlldr 的问题时，没有排查思路，但是靠着对 Linux 的使用和一些了解，想到了使用 strace 来追踪系统调用耗时，最终找到了网络相关的问题；也正是因为这个经历，在后续排查中也排上用场，找到了 nanosleep() 的耗时问题，为同事提供了关键词，最终找到 Oracle 的相关 Bug 报告。
看来还是要多学习 Linux 相关开发和性能测试工具，也可以更多地学习想要学习的 kernel 相关的知识。