在我的 Ubuntu 20.04 系统上，我启动了一个 Gnome 终端应用程序。这将启动 bash。在 bash 的新实例中，我运行ls或cd ..。在程序运行之前，某些东西会阻塞几秒钟。我想知道这是什么原因，以及如何更好地调试它。
第一次几乎总是发生这种情况。在新的终端/bash 实例中第一次运行后，同一命令运行良好。但另一个目录中的另一个命令可能再次变慢。
发生这种情况时，我已经perf trace在 bash 进程上运行了，只是为了ls在我的主目录中运行。这是输出：
? ( ): ... [continued]: pselect6()) = 1
0.019 ( 0.007 ms): read(buf: 0x7ffdb676be1f, count: 1) = 1
0.034 ( 0.005 ms): select(n: 1, inp: 0x7ffdb676bd40, exp: 0x7ffdb676bdc0, tvp: 0x7ffdb676bd30) = 0 (Timeout)
0.053 ( 0.008 ms): write(fd: 2</dev/pts/1>, buf: 0x55ec925b5bd0, count: 1) = 1
0.065 (117.862 ms): pselect6(n: 1, inp: 0x7ffdb676be20, sig: 0x7ffdb676bde0) = 1
117.944 ( 0.007 ms): read(buf: 0x7ffdb676be1f, count: 1) = 1
117.959 ( 0.004 ms): select(n: 1, inp: 0x7ffdb676bd40, exp: 0x7ffdb676bdc0, tvp: 0x7ffdb676bd30) = 0 (Timeout)
117.978 ( 0.006 ms): write(fd: 2</dev/pts/1>, buf: 0x55ec925b5bd0, count: 1) = 1
117.987 (565.240 ms): pselect6(n: 1, inp: 0x7ffdb676be20, sig: 0x7ffdb676bde0) = 1
683.246 ( 0.007 ms): read(buf: 0x7ffdb676be1f, count: 1) = 1
683.260 ( 0.008 ms): write(fd: 2</dev/pts/1>, buf: 0x55ec925b5bd0, count: 1) = 1
686.274 ( 0.022 ms): ioctl(cmd: TCGETS, arg: 0x7ffdb676bea0) = 0
686.299 ( 0.005 ms): ioctl(cmd: TCSETSW, arg: 0x7ffdb676be70) = 0
686.306 ( 0.002 ms): ioctl(cmd: TCGETS, arg: 0x7ffdb676be70) = 0
686.312 ( 0.003 ms): rt_sigaction(sig: INT, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
686.317 ( 0.002 ms): rt_sigaction(sig: TERM, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
686.322 ( 0.002 ms): rt_sigaction(sig: HUP, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
686.327 ( 0.002 ms): rt_sigaction(sig: ALRM, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
686.332 ( 0.002 ms): rt_sigaction(sig: WINCH, act: 0x7ffdb676bd10, oact: 0x7ffdb676bdb0, sigsetsize: 8) = 0
686.337 ( 0.003 ms): rt_sigaction(sig: INT, act: 0x7ffdb676bc70, oact: 0x7ffdb676bd10, sigsetsize: 8) = 0
19783.751 ( 0.010 ms): stat(filename: 0x8e1ab3b3, statbuf: 0x7ffdb676cc60) = 0
19783.764 ( 0.004 ms): stat(filename: 0x925961a0, statbuf: 0x7ffdb676cb50) = -1 ENOENT (No such file or directory)
19783.769 ( 0.001 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676cb50) = -1 ENOENT (No such file or directory)
19783.771 ( 0.001 ms): stat(filename: 0x925961d0, statbuf: 0x7ffdb676cb50) = -1 ENOENT (No such file or directory)
19783.774 ( 0.002 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676cb50) = -1 ENOENT (No such file or directory)
19783.777 ( 0.002 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676cb50) = -1 ENOENT (No such file or directory)
19783.780 ( 0.002 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676cb50) = -1 ENOENT (No such file or directory)
19783.782 ( 0.002 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676cb50) = -1 ENOENT (No such file or directory)
19783.785 ( 0.002 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676cb50) = 0
19783.788 ( 0.001 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676ca70) = 0
19783.791 ( 0.001 ms): geteuid() = 1000
19783.793 ( 0.001 ms): getegid() = 1000
19783.795 ( 0.001 ms): getuid() = 1000
19783.797 ( 0.001 ms): getgid() = 1000
19783.798 ( 0.005 ms): access(filename: 0x8fc536f0, mode: X) = 0
19783.804 ( 0.001 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676ca70) = 0
19783.807 ( 0.001 ms): geteuid() = 1000
19783.809 ( 0.001 ms): getegid() = 1000
19783.810 ( 0.001 ms): getuid() = 1000
19783.812 ( 0.001 ms): getgid() = 1000
19783.814 ( 0.001 ms): access(filename: 0x8fc536f0, mode: R) = 0
19783.816 ( 0.001 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676cb80) = 0
19783.818 ( 0.001 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676caa0) = 0
19783.820 ( 0.001 ms): geteuid() = 1000
19783.822 ( 0.001 ms): getegid() = 1000
19783.823 ( 0.001 ms): getuid() = 1000
19783.825 ( 0.001 ms): getgid() = 1000
19783.827 ( 0.001 ms): access(filename: 0x8fc536f0, mode: X) = 0
19783.829 ( 0.001 ms): stat(filename: 0x8fc536f0, statbuf: 0x7ffdb676caa0) = 0
19783.831 ( 0.001 ms): geteuid() = 1000
19783.833 ( 0.001 ms): getegid() = 1000
19783.834 ( 0.001 ms): getuid() = 1000
19783.836 ( 0.001 ms): getgid() = 1000
19783.838 ( 0.001 ms): access(filename: 0x8fc536f0, mode: R) = 0
19788.081 ( 0.011 ms): rt_sigprocmask(how: BLOCK, nset: 0x7ffdb676cc40, oset: 0x7ffdb676ccc0, sigsetsize: 8) = 0
19788.093 ( 0.012 ms): pipe(fildes: 0x55ec8e1e3738) = 0
19788.107 ( 0.742 ms): clone(clone_flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_tidptr: 0x7fd71d022a10) = 5948 (bash)
19788.863 ( 0.002 ms): setpgid(pid: 5948 (bash), pgid: 5948 (bash)) = 0
19788.879 ( 0.002 ms): rt_sigprocmask(how: SETMASK, nset: 0x7ffdb676ccc0, sigsetsize: 8) = 0
19788.903 ( 0.001 ms): rt_sigprocmask(how: BLOCK, nset: 0x7ffdb676cba0, oset: 0x7ffdb676cc20, sigsetsize: 8) = 0
19788.906 ( 0.002 ms): close(fd: 3) = 0
19788.909 ( 0.001 ms): close(fd: 4) = 0
19788.937 ( 0.003 ms): ioctl(fd: 255</dev/pts/1>, cmd: TIOCGPGRP, arg: 0x7ffdb676cb64) = 0
19788.943 ( 0.002 ms): rt_sigprocmask(how: SETMASK, nset: 0x7ffdb676cc20, sigsetsize: 8) = 0
19788.947 ( 0.002 ms): rt_sigprocmask(how: BLOCK, nset: 0x7ffdb676cca0, oset: 0x7ffdb676cd20, sigsetsize: 8) = 0
19788.953 ( 1.664 ms): wait4(upid: -1, stat_addr: 0x7ffdb676cc40, options: UNTRACED|CONTINUED) = 5948 (bash)
19790.626 ( 0.002 ms): rt_sigprocmask(how: BLOCK, nset: 0x7ffdb676cb60, oset: 0x7ffdb676cbe0, sigsetsize: 8) = 0
19790.630 ( 0.002 ms): ioctl(fd: 255</dev/pts/1>, cmd: TIOCSPGRP, arg: 0x7ffdb676cb4c) = 0
19790.633 ( 0.001 ms): rt_sigprocmask(how: SETMASK, nset: 0x7ffdb676cbe0, sigsetsize: 8) = 0
19790.636 ( 0.002 ms): ioctl(fd: 255</dev/pts/1>, cmd: TCGETS, arg: 0x7ffdb676cc40) = 0
19790.640 ( 0.002 ms): ioctl(fd: 255</dev/pts/1>, cmd: TIOCGWINSZ, arg: 0x7ffdb676cc50) = 0
19790.657 ( 0.002 ms): rt_sigprocmask(how: SETMASK, nset: 0x7ffdb676cd20, sigsetsize: 8) = 0
19790.665 ( 0.001 ms): wait4(upid: -1, stat_addr: 0x7ffdb676be90, options: NOHANG|UNTRACED|CONTINUED) = -1 ECHILD (No child processes)
19790.670 ( ): rt_sigreturn() ...
19790.682 ( 0.001 ms): rt_sigaction(sig: INT, act: 0x7ffdb676cc70, oact: 0x7ffdb676cd10, sigsetsize: 8) = 0
19790.694 ( 0.002 ms): rt_sigprocmask(how: BLOCK, oset: 0x7ffdb676cce0, sigsetsize: 8) = 0
19790.728 ( 0.006 ms): stat(filename: 0x8fb64ea0, statbuf: 0x7ffdb676ca10) = 0
19790.736 ( 0.002 ms): stat(filename: 0x925b7c50, statbuf: 0x7ffdb676c930) = 0
19790.739 ( 0.005 ms): openat(dfd: CWD, filename: 0x925b7c50, flags: APPEND|WRONLY) = 3
19790.746 ( 0.045 ms): write(fd: 3, buf: 0x55ec925b7bd0, count: 3) = 3
19790.793 ( 0.002 ms): close(fd: 3) = 0
19790.800 ( 0.009 ms): chown(filename: 0x925b7c50, user: 1000, group: 1000) = 0
19790.847 ( 0.002 ms): rt_sigprocmask(how: BLOCK, nset: 0x7ffdb676bdf0, oset: 0x7ffdb676be70, sigsetsize: 8) = 0
19790.851 ( 0.002 ms): ioctl(fd: 255</dev/pts/1>, cmd: TIOCSPGRP, arg: 0x7ffdb676bddc) = 0
19790.855 ( 0.001 ms): rt_sigprocmask(how: SETMASK, nset: 0x7ffdb676be70, sigsetsize: 8) = 0
19790.858 ( 0.002 ms): rt_sigaction(sig: INT, act: 0x7ffdb676bc70, oact: 0x7ffdb676bd10, sigsetsize: 8) = 0
19790.862 ( 0.002 ms): fcntl(cmd: GETFL) = RDWR
19790.885 ( 0.002 ms): ioctl(cmd: TIOCGWINSZ, arg: 0x7ffdb676be60) = 0
19790.888 ( 0.002 ms): ioctl(cmd: TIOCSWINSZ, arg: 0x7ffdb676be60) = 0
19790.891 ( 0.009 ms): ioctl(cmd: TCGETS, arg: 0x7ffdb676be30) = 0
19790.903 ( 0.001 ms): ioctl(cmd: TCGETS, arg: 0x7ffdb676be30) = 0
19790.906 ( 0.002 ms): ioctl(cmd: TCSETSW, arg: 0x7ffdb676be00) = 0
19790.909 ( 0.002 ms): ioctl(cmd: TCGETS, arg: 0x7ffdb676be00) = 0
19790.913 ( 0.002 ms): rt_sigprocmask(how: BLOCK, nset: 0x55ec8e1ef420, oset: 0x55ec8e1f5140, sigsetsize: 8) = 0
19790.916 ( 0.002 ms): rt_sigaction(sig: INT, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.920 ( 0.002 ms): rt_sigaction(sig: TERM, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.924 ( 0.001 ms): rt_sigaction(sig: HUP, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.927 ( 0.001 ms): rt_sigaction(sig: QUIT, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.930 ( 0.002 ms): rt_sigaction(sig: QUIT, act: 0x7ffdb676bc40, oact: 0x7ffdb676bce0, sigsetsize: 8) = 0
19790.933 ( 0.001 ms): rt_sigaction(sig: ALRM, act: 0x7ffdb676bba0, oact: 0x7ffdb676bc40, sigsetsize: 8) = 0
19790.935 ( 0.001 ms): rt_sigaction(sig: TSTP, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.938 ( 0.001 ms): rt_sigaction(sig: TSTP, act: 0x7ffdb676bc40, oact: 0x7ffdb676bce0, sigsetsize: 8) = 0
19790.940 ( 0.001 ms): rt_sigaction(sig: TTOU, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.942 ( 0.001 ms): rt_sigaction(sig: TTOU, act: 0x7ffdb676bc40, oact: 0x7ffdb676bce0, sigsetsize: 8) = 0
19790.945 ( 0.001 ms): rt_sigaction(sig: TTIN, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.947 ( 0.001 ms): rt_sigaction(sig: TTIN, act: 0x7ffdb676bc40, oact: 0x7ffdb676bce0, sigsetsize: 8) = 0
19790.950 ( 0.001 ms): rt_sigprocmask(how: SETMASK, nset: 0x55ec8e1f5140, sigsetsize: 8) = 0
19790.952 ( 0.001 ms): rt_sigaction(sig: WINCH, act: 0x7ffdb676bad0, oact: 0x7ffdb676bb70, sigsetsize: 8) = 0
19790.960 ( 0.006 ms): write(fd: 2</dev/pts/1>, buf: 0x55ec925b5bd0, count: 60) = 60
19790.969 (2622.411 ms): pselect6(n: 1, inp: 0x7ffdb676be20, sig: 0x7ffdb676bde0) = 1
22413.398 ( 0.007 ms): read(buf: 0x7ffdb676be1f, count: 1) = 1
22413.412 ( 0.005 ms): ioctl(cmd: TCGETS, arg: 0x7ffdb676bea0) = 0
22413.419 ( 0.004 ms): ioctl(cmd: TCSETSW, arg: 0x7ffdb676be70) = 0
22413.426 ( 0.003 ms): ioctl(cmd: TCGETS, arg: 0x7ffdb676be70) = 0
22413.433 ( 0.003 ms): rt_sigaction(sig: INT, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
22413.439 ( 0.003 ms): rt_sigaction(sig: TERM, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
22413.444 ( 0.002 ms): rt_sigaction(sig: HUP, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
22413.448 ( 0.002 ms): rt_sigaction(sig: ALRM, act: 0x7ffdb676bc50, oact: 0x7ffdb676bcf0, sigsetsize: 8) = 0
22413.453 ( 0.002 ms): rt_sigaction(sig: WINCH, act: 0x7ffdb676bd10, oact: 0x7ffdb676bdb0, sigsetsize: 8) = 0
22413.458 ( 0.002 ms): rt_sigaction(sig: INT, act: 0x7ffdb676bc70, oact: 0x7ffdb676bd10, sigsetsize: 8) = 0
22413.478 ( 0.008 ms): write(fd: 2</dev/pts/1>, buf: 0x55ec925b5bd0, count: 5) = 5
22413.492 ( 0.002 ms): rt_sigaction(sig: INT, act: 0x7ffdb676cc70, oact: 0x7ffdb676cd10, sigsetsize: 8) = 0
22413.498 ( 0.003 ms): rt_sigprocmask(how: BLOCK, nset: 0x7ffdb676ce10, oset: 0x7ffdb676ce90, sigsetsize: 8) = 0
22413.503 ( 0.002 ms): rt_sigprocmask(how: SETMASK, nset: 0x7ffdb676ce90, sigsetsize: 8) = 0
22413.508 ( 0.003 ms): setpgid(pgid: 5907 (bash)) = -1 EPERM (Operation not permitted)
22413.545 ( ): exit_group() = ?
观察最后一个rt_sigaction和第一个之间的疯狂延迟stat。stat这是 bash 开始在中搜索ls程序的时候PATH。但是为什么在开始这样做之前会有这种延迟？
答案1
我想我已经搞明白了。我的.bash_history文件中有 30 万行，HISTCONTROL=ignoreboth:erasedups设置了其余的配置，以便将历史记录附加到每个命令中以进行 bash 历史记录。所以我认为 bash 花费了时间进行重复数据删除和附加。并且cd ..和ls是我历史记录中非常常见的行，所以花了一些时间？不确定为什么旧事件持续存在，以至于它不得不一次又一次地尝试删除它们。无论如何，清除我的历史记录使事情变得很快。或者只是检查重复项就花了这么长时间。我还删除了erasedups以防万一。无论如何，我不想删除历史条目（以便历史记录中的一系列命令保持记录）。