How to interpret WCHAN Values for sleeping processes in RHEL 8

Environment

• Red Hat Enterprise Linux 8

Issue

• Certain user processes display a hyphen (-) in the WCHAN field despite being in a sleeping (S) state."

  # ps alx
  F   UID   PID  PPID PRI  NI    VSZ   RSS WCHAN  STAT TTY        TIME COMMAND
  [...]
  4     0   807     1  20   0 399784 28448 -      Ssl  ?          0:13 /usr/libexec/platform-python -Es /usr/sbin/tuned -l -P
  [...]
  4     0  1644     1  20   0  93048  9492 do_epo Ss   ?          0:00 /usr/lib/systemd/systemd --user
  [...]
  

Resolution

• Review /proc/<PID>/stack for deeper insight into the process wait state.

  # cat /proc/<PID>/stack
  

• Invoke the SysRq Show State feature and review the result in dmesg output:

    # echo t > /proc/sysrq-trigger
  
    # dmesg
  

Root Cause

• Red Hat Enterprise Linux 8 utilizes the Content from lwn.net is not included.ORC unwinder instead of the traditional frame pointer unwinder, optimizing .text code with the -fomit-frame-pointer option. Consequently, this optimized code does not create the stack frames required by /proc/<PID>/wchan, which expects a frame pointer layout.

Diagnostic Steps

• Certain functions, such as futex_wait_queue_me, do not create standard stack frames in Red Hat Enterprise Linux 8:

  # cat /proc/807/wchan; echo
  0
  

• Inspecting the task backtrace in crash it's possible to see futex_wait_queue_me in frame #2:

    crash> bt ffff89353c530000
    PID: 807    TASK: ffff89353c530000  CPU: 0   COMMAND: "tuned"
     #0 [ffffb3be80d0bbf0] __schedule at ffffffffb1a1b704
     #1 [ffffb3be80d0bc88] schedule at ffffffffb1a1bd18
     #2 [ffffb3be80d0bc90] futex_wait_queue_me at ffffffffb133dfc1                    <---
     #3 [ffffb3be80d0bcc8] futex_wait at ffffffffb133efef
     #4 [ffffb3be80d0bdf0] do_futex at ffffffffb1340b37
     #5 [ffffb3be80d0bec0] __x64_sys_futex at ffffffffb1341773
     #6 [ffffb3be80d0bf38] do_syscall_64 at ffffffffb120423b
     #7 [ffffb3be80d0bf50] entry_SYSCALL_64_after_hwframe at ffffffffb1c000ad
        RIP: 00007fa16f876032  RSP: 00007ffcecccfe80  RFLAGS: 00000246
        RAX: ffffffffffffffda  RBX: 00007ffcecccff20  RCX: 00007fa16f876032
        RDX: 0000000000000000  RSI: 0000000000000189  RDI: 000055c7aebf84c0
        RBP: 000055c7aebf84c0   R8: 0000000000000000   R9: 00000000ffffffff
        R10: 00007ffcecccff20  R11: 0000000000000246  R12: 0000000000000000
        R13: 0000000000000000  R14: 00007ffcecccff20  R15: 000055c7ae935330
        ORIG_RAX: 00000000000000ca  CS: 0033  SS: 002b
  
    crash> struct -x inactive_task_frame 0xffffb3be80d0bbf0
    struct inactive_task_frame {
      r15 = 0x0, 
      r14 = 0xffff8934f517e400, 
      r13 = 0xffffffffb2412780, 
      r12 = 0xffff89353c530000, 
      bx = 0xffff89353da23080, 
      bp = 0xffffb3be80d0bc80, 
      ret_addr = 0xffffffffb1a1b704
    }
  
    crash> rd -x 0xffffb3be80d0bc80
    ffffb3be80d0bc80:  ffffb3be803951c0 
  

• The rbp register does not have current stack pointer:

  crash> dis -l futex_wait_queue_me
  /usr/src/debug/kernel-4.18.0-80.el8/linux-4.18.0-80.el8.x86_64/kernel/futex.c: 2508
  0xffffffffb133df00 <futex_wait_queue_me>:       nopl   0x0(%rax,%rax,1) [FTRACE NOP]
  /usr/src/debug/kernel-4.18.0-80.el8/linux-4.18.0-80.el8.x86_64/kernel/futex.c: 2515
  0xffffffffb133df05 <futex_wait_queue_me+5>:     push   %r14
  0xffffffffb133df07 <futex_wait_queue_me+7>:     push   %r13
  0xffffffffb133df09 <futex_wait_queue_me+9>:     mov    %rdx,%r13
  0xffffffffb133df0c <futex_wait_queue_me+12>:    push   %r12
  0xffffffffb133df0e <futex_wait_queue_me+14>:    push   %rbp
  0xffffffffb133df0f <futex_wait_queue_me+15>:    mov    %rdi,%rbp                  <--- 
  0xffffffffb133df12 <futex_wait_queue_me+18>:    push   %rbx
  0xffffffffb133df13 <futex_wait_queue_me+19>:    mov    %rsi,%rbx
  0xffffffffb133df16 <futex_wait_queue_me+22>:    mov    %gs:0x15c80,%r12
  0xffffffffb133df1f <futex_wait_queue_me+31>:    sub    $0x8,%rsp
  0xffffffffb133df23 <futex_wait_queue_me+35>:    movq   $0x1,(%rsp)
  [...]
  

• Conversely, the rdp register has the current stack pointer in Red Hat Enterprise Linux 7:

  crash> dis -l futex_wait_queue_me
  /usr/src/debug/kernel-3.10.0-957.el7/linux-3.10.0-957.el7.x86_64/kernel/futex.c: 2081
  0xffffffff9dd0cd90 <futex_wait_queue_me>:       nopl   0x0(%rax,%rax,1) [FTRACE NOP]
  0xffffffff9dd0cd95 <futex_wait_queue_me+5>:     push   %rbp
  0xffffffff9dd0cd96 <futex_wait_queue_me+6>:     mov    %rsp,%rbp                  <---
  0xffffffff9dd0cd99 <futex_wait_queue_me+9>:     push   %r15
  0xffffffff9dd0cd9b <futex_wait_queue_me+11>:    mov    %rdi,%r15
  0xffffffff9dd0cd9e <futex_wait_queue_me+14>:    push   %r14
  0xffffffff9dd0cda0 <futex_wait_queue_me+16>:    push   %r13
  0xffffffff9dd0cda2 <futex_wait_queue_me+18>:    mov    %rdx,%r13
  0xffffffff9dd0cda5 <futex_wait_queue_me+21>:    push   %r12
  [...]
  

• The -fomit-frame-pointer flag is enabled in -O optimization option by default, so it does not create stack frame:

    $ cat test.c 
    void test(void){}
  
    $ gcc -o test.o -c test.c
  
    $ objdump -d test.o 
  
    test.o:     file format elf64-x86-64
  
    Disassembly of section .text:
  
    0000000000000000 <test>:
       0:	55                   	push   %rbp
       1:	48 89 e5             	mov    %rsp,%rbp
       4:	90                   	nop
       5:	5d                   	pop    %rbp
       6:	c3                   	retq   
  
    $ gcc -fomit-frame-pointer -o test.o -c test.c
    $ objdump -d test.o 
    
    test.o:     file format elf64-x86-64
    
    
    Disassembly of section .text:
    
    0000000000000000 <test>:
      0:	90                   	nop
       1:	c3                   	retq   
  

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.