missing semester - Debugging and Profiling
Debugging-调试
打印调试法与日志
“The most effective debugging tool is still careful thought, coupled with judiciously placed print statements” — Brian Kernighan, Unix for Beginners.
调试代码的第一种方法往往是在发现问题的地方添加一些打印语句,然后不断重复此过程直到获取了足够的信息并找到问题的根本原因。
另外一个方法是使用日志,而不是临时添加打印语句。日志较普通的打印语句有如下的一些优势:
- 您可以将日志写入文件、socket 或者甚至是发送到远端服务器而不仅仅是标准输出;
- 日志可以支持严重等级(例如 INFO, DEBUG, WARN, ERROR等),这使您可以根据需要过滤日志;
- 对于新发现的问题,很可能您的日志中已经包含了可以帮助您定位问题的足够的信息。
调试器
当通过打印已经不能满足您的调试需求时,您应该使用调试器。
调试器是一种可以允许我们和正在执行的程序进行交互的程序,它可以做到:
- 当到达某一行时将程序暂停;
- 一次一条指令地逐步执行程序;
- 程序崩溃后查看变量的值;
- 满足特定条件时暂停程序;
- 其他高级功能。
很多编程语言都有自己的调试器。Python 的调试器是pdb
。下面对pdb
支持的命令进行简单的介绍:
- l(ist) - 显示当前行附近的11行或继续执行之前的显示;
- s(tep) - 执行当前行,并在第一个可能的地方停止;
- n(ext) - 继续执行直到当前函数的下一条语句或者 return 语句;
- b(reak) - 设置断点(基于传入的参数);
- p(rint) - 在当前上下文对表达式求值并打印结果。还有一个命令是pp ,它使用
pprint
打印; - r(eturn) - 继续执行直到当前函数返回;
- q(uit) - 退出调试器。
对于更底层的编程语言,您可能需要了解一下 gdb
( 以及它的改进版 pwndbg
) 和 lldb
。
特殊工具
系统调用
即使需要调试的程序是一个二进制的黑盒程序,仍然有一些工具可以帮助到我们。
当程序需要执行一些只有操作系统内核才能完成的操作时,它需要使用 系统调用。有一些命令可以追踪您的程序执行的系统调用。在 Linux 中可以使用strace
,在 macOS 和 BSD 中可以使用 dtrace
。dtrace
用起来可能有些别扭,因为它使用的是它自有的 D
语言,但是我们可以使用一个叫做 dtruss
的封装使其具有和 strace
(更多信息参考 这里)类似的接口
# On Linux
sudo strace -e lstat ls -l > /dev/null
4
# On macOS
sudo dtruss -t lstat64_extended ls -l > /dev/null
网络抓包
有些情况下,我们需要查看网络数据包才能定位问题。像 tcpdump
和 Wireshark 这样的网络数据包分析工具可以帮助您获取网络数据包的内容并基于不同的条件进行过滤。
前端开发
对于 web 开发, Chrome/Firefox 的开发者工具非常方便,功能也很强大:
- 源码 -查看任意站点的 HTML/CSS/JS 源码;
- 实时地修改 HTML, CSS, JS 代码 - 修改网站的内容、样式和行为用于测试(从这一点您也能看出来,网页截图是不可靠的);
- Javascript shell - 在 JS REPL中执行命令;
- 网络 - 分析请求的时间线;
- 存储 - 查看 Cookies 和本地应用存储。
静态分析
有些问题是不需要执行代码就能发现的。静态分析会将程序的源码作为输入然后基于编码规则对其进行分析并对代码的正确性进行推理。
大多数的编辑器和 IDE 都支持在编辑界面显示这些工具的分析结果、高亮有警告和错误的位置。 这个过程通常称为 code linting 。风格检查或安全检查的结果同样也可以进行相应的显示。
在 vim 中,有 ale
或 syntastic
可以做同样的事情。 在 Python 中, pylint
和 pep8
是两种用于进行风格检查的工具,而 bandit
工具则用于检查安全相关的问题。
对于风格检查和代码格式化,还有以下一些工具可以作为补充:用于 Python 的 black
、用于 Go 语言的 gofmt
、用于 Rust 的 rustfmt
或是用于 JavaScript, HTML 和 CSS 的 prettier
。这些工具可以自动格式化代码,这样代码风格就可以与常见的风格保持一致。
Profiling-性能分析
代码能跑起来不一定是成功的,可能在时间和内存上存在一定问题。
计时
大多数情况下只需要打印两处代码之间的时间即可发现问题。
import time, random
n = random.randint(1, 10) * 100
# 获取当前时间
start = time.time()
# 执行一些操作
print("Sleeping for {} ms".format(n))
time.sleep(n/1000)
# 比较当前时间和起始时间
print(time.time() - start)
# Output
# Sleeping for 500 ms
# 0.5713930130004883
执行时间(wall clock time)不一定是该程序实际在CPU上运行的时间,(分时系统,时间片到期后需等待调度)
对于工具来说,需要区分真实时间、用户时间和系统时间。通常来说,用户时间+系统时间代表了您的进程所消耗的实际 CPU (更详细的解释可以参照这篇文章)。
- 真实时间 - 从程序开始到结束流失掉的真实时间,包括其他进程的执行时间以及阻塞消耗的时间(例如等待 I/O或网络);
- User - CPU 执行用户代码所花费的时间;
- Sys - CPU 执行系统内核代码所花费的时间。
$ time curl https://missing.csail.mit.edu &> /dev/null`
real 0m2.561s
user 0m0.015s
sys 0m0.012s
性能分析工具(profilers)
CPU
大多数情况下,当人们提及性能分析工具的时候,通常指的是 CPU 性能分析工具。
CPU 性能分析工具有两种: 追踪分析器(tracing)及采样分析器(sampling)。
追踪分析器会记录程序的每一次函数调用,而采样分析器则只会周期性的监测(通常为每毫秒)您的程序并记录程序堆栈。
在 Python 中,使用 cProfile
模块来分析每次函数调用所消耗的时间。
$ python -m cProfile -s tottime grep.py 1000 '^(import|\s*def)[^,]*$' *.py
[omitted program output]
ncalls tottime percall cumtime percall filename:lineno(function)
8000 0.266 0.000 0.292 0.000 {built-in method io.open}
8000 0.153 0.000 0.894 0.000 grep.py:5(grep)
17000 0.101 0.000 0.101 0.000 {built-in method builtins.print}
8000 0.100 0.000 0.129 0.000 {method 'readlines' of '_io._IOBase' objects}
93000 0.097 0.000 0.111 0.000 re.py:286(_compile)
93000 0.069 0.000 0.069 0.000 {method 'search' of '_sre.SRE_Pattern' objects}
93000 0.030 0.000 0.141 0.000 re.py:231(compile)
17000 0.019 0.000 0.029 0.000 codecs.py:318(decode)
1 0.017 0.017 0.911 0.911 grep.py:3(<module>)
[omitted lines]
关于 Python 的 cProfile
分析器(以及其他一些类似的分析器),需要注意的是它显示的是每次函数调用的时间。
更加符合直觉的显示分析信息的方式是包括每行代码的执行时间,这也是行分析器的工作。使用 line_profiler
,它会基于行来显示时间:
$ kernprof -l -v a.py
Wrote profile results to urls.py.lprof
Timer unit: 1e-06 s
Total time: 0.636188 s
File: a.py
Function: get_urls at line 5
Line # Hits Time Per Hit % Time Line Contents
==============================================================
5 @profile
6 def get_urls():
7 1 613909.0 613909.0 96.5 response = requests.get('https://missing.csail.mit.edu')
8 1 21559.0 21559.0 3.4 s = BeautifulSoup(response.content, 'lxml')
9 1 2.0 2.0 0.0 urls = []
10 25 685.0 27.4 0.1 for url in s.find_all('a'):
11 24 33.0 1.4 0.0 urls.append(url['href'])
内存
像 C 或者 C++ 这样的语言,内存泄漏会导致您的程序在使用完内存后不去释放它。为了应对内存类的 Bug,我们可以使用类似 Valgrind 这样的工具来检查内存泄漏问题。
时间分析
在使用strace
调试代码时,可能会希望忽略一些特殊的代码并希望在分析时将其当作黑盒处理。perf
命令将 CPU 的区别进行了抽象,它不会报告时间和内存的消耗,而是报告与您的程序相关的系统事件。
例如,perf
可以报告不佳的缓存局部性(poor cache locality)、大量的页错误(page faults)或活锁(livelocks)。下面是关于常见命令的简介:
perf list
- 列出可以被 pref 追踪的事件;perf stat COMMAND ARG1 ARG2
- 收集与某个进程或指令相关的事件;perf record COMMAND ARG1 ARG2
- 记录命令执行的采样信息并将统计数据储存在perf.data
中;perf report
- 格式化并打印perf.data
中的数据。
可视化
使用分析器来分析真实的程序时,由于软件的复杂性,其输出结果中将包含大量的信息。人类是一种视觉动物,非常不善于阅读大量的文字。因此很多工具都提供了可视化分析器输出结果的功能。
- 火焰图是一种显示 CPU 分析数据的形式,火焰图会在 Y 轴显示函数调用关系,并在 X 轴显示其耗时的比例。火焰图同时还是可交互的,可以深入程序的某一具体部分,并查看其栈追踪。
- 调用图和控制流图可以显示子程序之间的关系,它将函数作为节点并把函数调用作为边。将它们和分析器的信息(例如调用次数、耗时等)放在一起使用时,调用图会变得非常有用,它可以帮助我们分析程序的流程。 在 Python 中可以使用
pycallgraph
来生成这些图片。
资源监控
有时候,分析程序性能的第一步是搞清楚它所消耗的资源。程序变慢通常是因为它所需要的资源不够了。例如,没有足够的内存或者网络连接变慢的时候。
有很多很多的工具可以被用来显示不同的系统资源,例如 CPU 占用、内存使用、网络、磁盘使用等。
- 通用监控 - 最流行的工具要数
htop
了,它是top
的改进版。htop
可以显示当前运行进程的多种统计信息。如果需要合并测量全部的进程,dstat
是也是一个非常好用的工具,它可以实时地计算不同子系统资源的度量数据,例如 I/O、网络、 CPU 利用率、上下文切换等等; - I/O 操作 -
iotop
可以显示实时 I/O 占用信息而且可以非常方便地检查某个进程是否正在执行大量的磁盘读写操作; - 磁盘使用 -
df
可以显示每个分区的信息,而du
则可以显示当前目录下每个文件的磁盘使用情况( disk usage)。-h
选项可以使命令以对人类(human)更加友好的格式显示数据;ncdu
是一个交互性更好的du
,它可以让您在不同目录下导航、删除文件和文件夹; - 内存使用 -
free
可以显示系统当前空闲的内存。内存也可以使用htop
这样的工具来显示; - 打开文件 -
lsof
可以列出被进程打开的文件信息。 当我们需要查看某个文件是被哪个进程打开的时候,这个命令非常有用; - 网络连接和配置 -
ss
能帮助我们监控网络包的收发情况以及网络接口的显示信息。ss
常见的一个使用场景是找到端口被进程占用的信息。如果要显示路由、网络设备和接口信息,您可以使用ip
命令。注意,netstat
和ifconfig
这两个命令已经被前面那些工具所代替了。 - 网络使用 -
nethogs
和iftop
是非常好的用于对网络占用进行监控的交互式命令行工具。
如果希望测试一下这些工具,可以使用 stress
命令来为系统人为地增加负载。
特殊工具
有时候,只需要对黑盒程序进行基准测试,并依此对软件选择进行评估。
hyperfine
这样的命令行可以进行基准测试。例如,下面的例子中,我们可以看到fd
比 find
要快20倍。
$ hyperfine --warmup 3 'fd -e jpg' 'find . -iname "*.jpg"'
Benchmark #1: fd -e jpg
Time (mean ± σ): 51.4 ms ± 2.9 ms [User: 121.0 ms, System: 160.5 ms]
Range (min … max): 44.2 ms … 60.1 ms 56 runs
Benchmark #2: find . -iname "*.jpg"
Time (mean ± σ): 1.126 s ± 0.101 s [User: 141.1 ms, System: 956.1 ms]
Range (min … max): 0.975 s … 1.287 s 10 runs
Summary
'fd -e jpg' ran
21.89 ± 2.33 times faster than 'find . -iname "*.jpg"'