2

Running this

strace -ff -tt perl -e 'open(A,"<","/proc/cpuinfo");'

gives this:

22:36:10.365187 openat(AT_FDCWD, "/proc/cpuinfo", O_RDONLY) = 3
22:36:10.382061 ioctl(3, TCGETS, 0x7fffb127ea50) = -1 ENOTTY (Inappropriate ioctl for device)

/proc/cpuinfo is an in-memory file that does not require access to a slow disk. Why is it taking 17 ms to open?

I have tested 10 times on an idle system and the timing is very consistent.

$ uname -a
Linux hk 4.15.0-20-generic #21-Ubuntu SMP Tue Apr 24 06:16:15 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
Ole Tange
  • 35,514
  • /proc contents are not in-memory files. They're a means to communicate with the kernel and devices. – steve Jun 23 '19 at 20:58
  • I'm no expert on syscalls, but opening itself doesn't take so long - openat already returns fd 3 at the timestamp listed. Likely there's something else going on. Wild guess would be that the process is put on hold by the CPU itself and other processes are taken care of in the mean time. I'd guess if you set priority/niceness value higher you'd see decrease in the time – Sergiy Kolodyazhnyy Jun 23 '19 at 20:59
  • 1
    Hint: -T option shows time durations of syscalls. Also, I've reproduced this on Linux kernel 5.1.9: openat(AT_FDCWD, "/proc/cpuinfo", O_RDONLY) = 3 <0.016822> - 17 msec. – Danila Kiver Jun 24 '19 at 14:46

1 Answers1

5

Since version 4.12 of the kernel, on x86 CPUs with support for the APERF / MPERF MSRs, there’s a slight delay when opening /proc/cpuinfo to ensure that the CPU frequencies are accurately reported (or at least, don’t show values which are too stale). This was changed slightly in cpufreq: x86: Make scaling_cur_freq behave more as expected (4.13, with increased delays) and again in x86 / CPU: Always show current CPU frequency in /proc/cpuinfo (4.14, with reduced delays).

Stephen Kitt
  • 434,908
  • That looks about right. This is only slow the in the first round: for t in {1..100}; do time cat /proc/cpuinfo >/dev/null;sleep 0.99;done – Ole Tange Jun 24 '19 at 19:17