[Crash-utility] [PATCH] fix for "sys -c" option for certain vmcores

[Kazuhito Hagio]

On 5/30/2019 5:03 PM, Dave Anderson wrote:
> 
> 
> ----- Original Message -----
>> Hi Dave,
>>
>> I don't know why this difference arises, but with certain kernel configurations,
>> the source file and line information of the schedule() function becomes the
>> following, not "/kernel/sched/core.c".
>>
>>   crash> sym schedule
>>   ffffffffab0d3666 (T) schedule
>>   /share/src/linux-5.0.1/./arch/x86/include/asm/current.h: 15
> 
> Yeah, presumably happens because your kernel doesn't have the ftrace nop compiled
> into the beginning of each function.  When it does, the first address in the
> schedule function would be in kernel/sched/core.c:
> 
>   crash> sym schedule
>   ffffffffa22b5dc0 (T) schedule /usr/src/debug/kernel-5.2.0-0.rc2.1.elrdy/linux-5.2.0-0.rc2.1.elrdy.x86_64/kernel/sched/core.c: 3503
>   crash> dis -l schedule
>   /usr/src/debug/kernel-5.2.0-0.rc2.1.elrdy/linux-5.2.0-0.rc2.1.elrdy.x86_64/kernel/sched/core.c: 3503
>   0xffffffffa22b5dc0 <schedule>:  nopl   0x0(%rax,%rax,1) [FTRACE NOP]
>   /usr/src/debug/kernel-5.2.0-0.rc2.1.elrdy/linux-5.2.0-0.rc2.1.elrdy.x86_64/./arch/x86/include/asm/current.h: 15
>   0xffffffffa22b5dc5 <schedule+5>:        push   %rbx
>   0xffffffffa22b5dc6 <schedule+6>:        mov    %gs:0x15f00,%rbx
>   /usr/src/debug/kernel-5.2.0-0.rc2.1.elrdy/linux-5.2.0-0.rc2.1.elrdy.x86_64/kernel/sched/core.c: 3506
>   0xffffffffa22b5dcf <schedule+15>:       mov    0x10(%rbx),%rax
>   0xffffffffa22b5dd3 <schedule+19>:       test   %rax,%rax
>   0xffffffffa22b5dd6 <schedule+22>:       je     0xffffffffa22b5de2 <schedule+34>
>   ...

Ah, I see. Thanks! I think it is CONFIG_DYNAMIC_FTRACE,
which the config does not have.

  $ grep FTRACE config-5.0.1
  CONFIG_HAVE_KPROBES_ON_FTRACE=y
  CONFIG_HAVE_DYNAMIC_FTRACE=y
  CONFIG_HAVE_DYNAMIC_FTRACE_WITH_REGS=y
  CONFIG_HAVE_FTRACE_MCOUNT_RECORD=y
  CONFIG_FTRACE=y
  # CONFIG_FTRACE_SYSCALLS is not set
  # CONFIG_FTRACE_STARTUP_TEST is not set

Thanks,
Kazu

> 
> If ftrace is not enabled, then it would show asm/current.h because the first instruction
> in schedule() is the evaluation of "current": 
> 
>   asmlinkage __visible void __sched schedule(void)
>   {
>           struct task_struct *tsk = current;
> 
> which is #define'd in asm/current.h:
> 
>   #define get_current() (current_thread_info()->task)
>   #define current get_current()
> 
> Anyway, I'll take a look and test the patch tomorrow.
> 
> Thanks,
>   Dave
> 
>>
>> This causes the "sys -c" option not to print the information of system calls,
>> and makes it very slow.
>>
>>   crash> sys -c | sh -c 'time cat'
>>   NUM  SYSTEM CALL                FILE AND LINE NUMBER
>>     0  __x64_sys_read
>>     1  __x64_sys_write
>>     2  __x64_sys_open
>>   ...
>>   333  __x64_sys_io_pgetevents
>>   334  __x64_sys_rseq
>>
>>   real    2m32.669s
>>   user    0m0.002s
>>   sys     0m0.022s
>>
>> With this patch, the option can print the information in not too long time:
>>
>>   crash> sys -c | sh -c 'time cat'
>>   NUM  SYSTEM CALL                FILE AND LINE NUMBER
>>     0  __x64_sys_read             ../fs/read_write.c: 588
>>     1  __x64_sys_write            ../fs/read_write.c: 610
>>     2  __x64_sys_open             ../fs/open.c: 1079
>>   ...
>>   333  __x64_sys_io_pgetevents    ../fs/aio.c: 2139
>>   334  __x64_sys_rseq             ../kernel/rseq.c: 308
>>
>>   real    0m10.905s
>>   user    0m0.000s
>>   sys     0m0.024s
>>
>> Also, in dump_sys_call_table(), it looks like there is no need to call
>> get_build_directory() for each system call, so moving it out of the loop
>> makes it faster.
>>
>> [without moving the get_build_directory()]
>>   real    0m15.862s
>>   user    0m0.003s
>>   sys     0m0.020s
>>
>> Signed-off-by: Kazuhito Hagio <k-hagio at ab.jp.nec.com>
>> ---
>>  kernel.c  | 2 +-
>>  symbols.c | 2 +-
>>  2 files changed, 2 insertions(+), 2 deletions(-)
>>
>> diff --git a/kernel.c b/kernel.c
>> index db25f22e4ec6..22909d28cefc 100644
>> --- a/kernel.c
>> +++ b/kernel.c
>> @@ -5679,6 +5679,7 @@ dump_sys_call_table(char *spec, int cnt)
>>  
>>  	fprintf(fp, "%s", sys_call_hdr);
>>  
>> +	get_build_directory(buf2);
>>          for (i = 0, sct = sys_call_table; i < NR_syscalls; i++, sct++) {
>>                  if (!(scp = value_symbol(*sct))) {
>>  			if (confirmed || CRASHDEBUG(1)) {
>> @@ -5710,7 +5711,6 @@ dump_sys_call_table(char *spec, int cnt)
>>  	  	 */
>>                  sp = value_search(*sct, NULL);
>>                  spn = next_symbol(NULL, sp);
>> -		get_build_directory(buf2);
>>  
>>  		for (addr = *sct; sp && spn && (addr < spn->value); addr++) {
>>  			BZERO(buf1, BUFSIZE);
>> diff --git a/symbols.c b/symbols.c
>> index 863d1f0a8e25..3ce8692fd397 100644
>> --- a/symbols.c
>> +++ b/symbols.c
>> @@ -4296,7 +4296,7 @@ get_build_directory(char *buf)
>>  		get_line_number(symbol_value("do_schedule"), buf, FALSE);
>>  	else
>>  		return NULL;
>> -	if ((p = strstr(buf, "/kernel/")))
>> +	if ((p = strstr(buf, "/kernel/")) || (p = strstr(buf, "/./arch/")))
>>  		*p = NULLCHAR;
>>  	else
>>  		return(NULL);
>> --
>> 2.18.1
>>
> 
> --
> Crash-utility mailing list
> Crash-utility at redhat.com
> https://www.redhat.com/mailman/listinfo/crash-utility
>