ACPICA Trace Facility

ACPICA trace facility와 log reducer

이 문서는 Intel Corporation의 Lv Zheng이 작성한 ACPICA method tracing facility의 기능과 인터페이스를 설명한다. ACPICA는 method tracing 능력을 바탕으로 `log reducer`와 `AML tracer`라는 두 기능을 제공한다.

`CONFIG_ACPI_DEBUG`가 활성화되면 ACPICA subsystem은 `ACPI_DEBUG_PRINT()` macro로 debugging output을 만든다. 이 message는 component별 `debug layer`와 type별 `debug level`이라는 두 단계에서 줄일 수 있으며, 각각 `/sys/module/acpi/parameters/debug_layer`와 `/sys/module/acpi/parameters/debug_level`로 설정한다.

그러나 특정 layer와 level을 control method evaluation 전체에 적용하면 kernel log buffer에 담기 어려울 만큼 출력이 많을 수 있다. Log reducer는 control method evaluation이 시작될 때만 선택한 상세 layer와 level을 임시로 활성화하고, evaluation이 끝나면 상세 logging을 비활성화한다.

.. SPDX-License-Identifier: GPL-2.0
.. include:: <isonum.txt>

=====================
ACPICA Trace Facility
=====================

:Copyright: |copy| 2015, Intel Corporation
:Author: Lv Zheng <lv.zheng@intel.com>


Abstract
========
This document describes the functions and the interfaces of the
method tracing facility.

Functionalities and usage examples
==================================

ACPICA provides method tracing capability. And two functions are
currently implemented using this capability.

Log reducer
-----------

ACPICA subsystem provides debugging outputs when CONFIG_ACPI_DEBUG is
enabled. The debugging messages which are deployed via
ACPI_DEBUG_PRINT() macro can be reduced at 2 levels - per-component
level (known as debug layer, configured via
/sys/module/acpi/parameters/debug_layer) and per-type level (known as
debug level, configured via /sys/module/acpi/parameters/debug_level).

But when the particular layer/level is applied to the control method
evaluations, the quantity of the debugging outputs may still be too
large to be put into the kernel log buffer. The idea thus is worked out
to only enable the particular debug layer/level (normally more detailed)
logs when the control method evaluation is started, and disable the
detailed logging when the control method evaluation is stopped.

Log reducer 설정 예

첫 번째 예는 `/sys/module/acpi/parameters`로 이동한 뒤 `trace_debug_layer`에 `0xXXXXXXXX`, `trace_debug_level`에 `0xYYYYYYYY`를 쓰고 `trace_state`를 `enable`로 설정한다. 이 방식은 모든 control method가 evaluation되는 동안 선택한 layer/level과 일치하는 log를 대상으로 한다.

두 번째 예는 위 두 mask에 더해 `trace_method_name`에 ACPI namespace의 전체 경로 `\PPPP.AAAA.TTTT.HHHH`를 쓰고 `trace_state`를 `method`로 설정한다. 그러면 지정한 control method가 evaluation되는 동안 일치하는 log를 기록한다.

세 번째 예는 같은 method path를 사용하되 `trace_state`를 `method-once`로 설정한다. 지정한 control method가 처음 evaluation될 때 한 번만 일치하는 log를 기록한다.

`0xXXXXXXXX`와 `0xYYYYYYYY`에 사용할 수 있는 debug layer/level mask 값은 `Documentation/firmware-guide/acpi/debug.rst`를 참조한다. `\PPPP.AAAA.TTTT.HHHH`는 ACPI namespace에서 찾을 수 있는 control method의 전체 경로이며, control method evaluation의 최상위 진입 method일 필요는 없다.

The following command examples illustrate the usage of the "log reducer"
functionality:

a. Filter out the debug layer/level matched logs when control methods
   are being evaluated::

      # cd /sys/module/acpi/parameters
      # echo "0xXXXXXXXX" > trace_debug_layer
      # echo "0xYYYYYYYY" > trace_debug_level
      # echo "enable" > trace_state

b. Filter out the debug layer/level matched logs when the specified
   control method is being evaluated::

      # cd /sys/module/acpi/parameters
      # echo "0xXXXXXXXX" > trace_debug_layer
      # echo "0xYYYYYYYY" > trace_debug_level
      # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name
      # echo "method" > /sys/module/acpi/parameters/trace_state

c. Filter out the debug layer/level matched logs when the specified
   control method is being evaluated for the first time::

      # cd /sys/module/acpi/parameters
      # echo "0xXXXXXXXX" > trace_debug_layer
      # echo "0xYYYYYYYY" > trace_debug_level
      # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name
      # echo "method-once" > /sys/module/acpi/parameters/trace_state

Where:
   0xXXXXXXXX/0xYYYYYYYY
     Refer to Documentation/firmware-guide/acpi/debug.rst for possible debug layer/level
     masking values.
   \PPPP.AAAA.TTTT.HHHH
     Full path of a control method that can be found in the ACPI namespace.
     It needn't be an entry of a control method evaluation.

AML tracer의 trace point

Method tracing facility는 AML interpreter가 control method 또는 AML opcode 실행을 시작하거나 끝내는 trace point에 특별한 log entry를 추가한다. 이 log entry 형식은 향후 변경될 수 있으므로 parser가 예시의 열 위치나 문자열을 영구 ABI처럼 가정해서는 안 된다.

예시 trace는 `\_SB.PCI0.LPCB.ECOK`의 `Method Begin`으로 시작한다. 이어서 `If`, `LEqual`, `-NamePath-`, `One`, `Return` opcode의 `Opcode Begin`과 `Opcode End`가 실행 중첩 순서에 따라 나타나고, 마지막에 같은 method의 `Method End`가 기록된다.

개발자는 이 entry를 이용해 AML interpretation 흐름을 추적하고 문제 debugging과 performance tuning에 활용할 수 있다. AML tracer log도 `ACPI_DEBUG_PRINT()` macro로 구현되므로, 이를 사용하려면 kernel에서 `CONFIG_ACPI_DEBUG`가 활성화되어 있어야 한다.

AML tracer
----------

There are special log entries added by the method tracing facility at
the "trace points" the AML interpreter starts/stops to execute a control
method, or an AML opcode. Note that the format of the log entries are
subject to change::

   [    0.186427]   exdebug-0398 ex_trace_point        : Method Begin [0xf58394d8:\_SB.PCI0.LPCB.ECOK] execution.
   [    0.186630]   exdebug-0398 ex_trace_point        : Opcode Begin [0xf5905c88:If] execution.
   [    0.186820]   exdebug-0398 ex_trace_point        : Opcode Begin [0xf5905cc0:LEqual] execution.
   [    0.187010]   exdebug-0398 ex_trace_point        : Opcode Begin [0xf5905a20:-NamePath-] execution.
   [    0.187214]   exdebug-0398 ex_trace_point        : Opcode End [0xf5905a20:-NamePath-] execution.
   [    0.187407]   exdebug-0398 ex_trace_point        : Opcode Begin [0xf5905f60:One] execution.
   [    0.187594]   exdebug-0398 ex_trace_point        : Opcode End [0xf5905f60:One] execution.
   [    0.187789]   exdebug-0398 ex_trace_point        : Opcode End [0xf5905cc0:LEqual] execution.
   [    0.187980]   exdebug-0398 ex_trace_point        : Opcode Begin [0xf5905cc0:Return] execution.
   [    0.188146]   exdebug-0398 ex_trace_point        : Opcode Begin [0xf5905f60:One] execution.
   [    0.188334]   exdebug-0398 ex_trace_point        : Opcode End [0xf5905f60:One] execution.
   [    0.188524]   exdebug-0398 ex_trace_point        : Opcode End [0xf5905cc0:Return] execution.
   [    0.188712]   exdebug-0398 ex_trace_point        : Opcode End [0xf5905c88:If] execution.
   [    0.188903]   exdebug-0398 ex_trace_point        : Method End [0xf58394d8:\_SB.PCI0.LPCB.ECOK] execution.

Developers can utilize these special log entries to track the AML
interpretation, thus can aid issue debugging and performance tuning. Note
that, as the "AML tracer" logs are implemented via ACPI_DEBUG_PRINT()
macro, CONFIG_ACPI_DEBUG is also required to be enabled for enabling
"AML tracer" logs.

AML tracer mode와 boot parameter

AML tracer의 기본 mask는 `trace_debug_layer=0x80`과 `trace_debug_level=0x10`이다. `trace_state=enable`은 control method가 evaluation될 때 method 시작/종료 trace를 전체 범위에서 수집한다.

특정 method만 추적하려면 `trace_method_name`에 `\PPPP.AAAA.TTTT.HHHH`를 쓰고 `trace_state=method`를 선택한다. 첫 evaluation 한 번만 필요하면 `method-once`를 사용한다.

지정 method 내부의 method 경계뿐 아니라 opcode 경계까지 추적하려면 `trace_state=opcode`를 사용한다. 첫 evaluation 한 번의 method/opcode trace만 수집하는 mode는 뒤의 인터페이스 설명과 boot parameter 예에서 `opcode-once`로 정의된다.

원문의 다섯 번째 shell 예는 `trace_state`에 `opcode-opcode`를 쓰지만, 같은 문서의 mode 목록과 바로 뒤 boot parameter 예는 `opcode-once`를 사용한다. 원문 명령은 보존하되 실제 설정에서는 정의된 값인 `opcode-once`를 사용해야 한다.

Method tracing과 관련된 모든 module parameter는 boot parameter로도 지정할 수 있다. 예시는 `acpi.trace_debug_layer=0x80`, `acpi.trace_debug_level=0x10`, `acpi.trace_method_name=\_SB.LID0._LID`, `acpi.trace_state=opcode-once`를 kernel command line에 연속해서 배치한다.

The following command examples illustrate the usage of the "AML tracer"
functionality:

a. Filter out the method start/stop "AML tracer" logs when control
   methods are being evaluated::

      # cd /sys/module/acpi/parameters
      # echo "0x80" > trace_debug_layer
      # echo "0x10" > trace_debug_level
      # echo "enable" > trace_state

b. Filter out the method start/stop "AML tracer" when the specified
   control method is being evaluated::

      # cd /sys/module/acpi/parameters
      # echo "0x80" > trace_debug_layer
      # echo "0x10" > trace_debug_level
      # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name
      # echo "method" > trace_state

c. Filter out the method start/stop "AML tracer" logs when the specified
   control method is being evaluated for the first time::

      # cd /sys/module/acpi/parameters
      # echo "0x80" > trace_debug_layer
      # echo "0x10" > trace_debug_level
      # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name
      # echo "method-once" > trace_state

d. Filter out the method/opcode start/stop "AML tracer" when the
   specified control method is being evaluated::

      # cd /sys/module/acpi/parameters
      # echo "0x80" > trace_debug_layer
      # echo "0x10" > trace_debug_level
      # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name
      # echo "opcode" > trace_state

e. Filter out the method/opcode start/stop "AML tracer" when the
   specified control method is being evaluated for the first time::

      # cd /sys/module/acpi/parameters
      # echo "0x80" > trace_debug_layer
      # echo "0x10" > trace_debug_level
      # echo "\PPPP.AAAA.TTTT.HHHH" > trace_method_name
      # echo "opcode-opcode" > trace_state

Note that all above method tracing facility related module parameters can
be used as the boot parameters, for example::

   acpi.trace_debug_layer=0x80 acpi.trace_debug_level=0x10 \
   acpi.trace_method_name=\_SB.LID0._LID acpi.trace_state=opcode-once

ACPI module parameter 인터페이스

모든 method tracing 기능은 `/sys/module/acpi/parameters/`에서 접근할 수 있는 ACPI module parameter로 설정한다. `trace_method_name`에는 사용자가 추적하려는 AML method의 전체 경로를 기록한다.

전체 path의 각 name segment에는 뒤쪽을 채우는 trailing `_`를 포함하지 않아야 한다. 반면 namespace root에서 시작하는 absolute path를 만들기 위한 `\`는 포함할 수 있다.

`trace_debug_layer`는 tracing 기능이 활성화된 동안 임시로 사용할 `debug_layer`이다. 기본값은 모든 AML tracer log와 일치시키는 layer인 `ACPI_EXECUTER (0x80)`이다.

`trace_debug_level`은 tracing이 활성화된 동안 임시로 사용할 `debug_level`이다. 기본값은 모든 AML tracer log와 일치시키는 level인 `ACPI_LV_TRACE_POINT (0x10)`이다.

`trace_state`는 tracing 기능의 상태와 범위를 선택한다. 사용자는 `echo string > /sys/module/acpi/parameters/trace_state` 형식으로 다음 절에 정의된 문자열 중 하나를 써서 debug tracing을 활성화하거나 비활성화한다.

Interface descriptions
======================

All method tracing functions can be configured via ACPI module
parameters that are accessible at /sys/module/acpi/parameters/:

trace_method_name
  The full path of the AML method that the user wants to trace.

  Note that the full path shouldn't contain the trailing "_"s in its
  name segments but may contain "\" to form an absolute path.

trace_debug_layer
  The temporary debug_layer used when the tracing feature is enabled.

  Using ACPI_EXECUTER (0x80) by default, which is the debug_layer
  used to match all "AML tracer" logs.

trace_debug_level
  The temporary debug_level used when the tracing feature is enabled.

  Using ACPI_LV_TRACE_POINT (0x10) by default, which is the
  debug_level used to match all "AML tracer" logs.

trace_state
  The status of the tracing feature.

  Users can enable/disable this debug tracing feature by executing
  the following command::

   # echo string > /sys/module/acpi/parameters/trace_state

Where "string" should be one of the following:

trace_state 값과 fallback 규칙

`disable`은 method tracing 기능을 끈다. `enable`은 기능을 켜고, 모든 method 실행 중 `trace_debug_layer/trace_debug_level`과 일치하는 ACPICA debugging message를 기록한다.

`method`는 `trace_method_name`으로 지정한 method가 실행되는 동안 일치하는 message를 기록한다. `method-once`는 같은 범위를 첫 실행 한 번으로 제한한다.

`opcode`는 지정 method의 method 실행과 그 안의 opcode 실행 동안 일치하는 message를 기록한다. `opcode-once`는 method/opcode 범위를 지정 method의 첫 실행 한 번만 기록한다.

`enable`은 mask를 모든 control method evaluation에 적용하므로 특정 method 이름이 필요 없다. 따라서 `trace_state`를 `enable`로 설정하면 `trace_method_name`은 `NULL`로 reset된다.

`method` 또는 `opcode` 계열 mode를 선택했는데 `trace_method_name`이 `NULL`이면, `trace_debug_layer/trace_debug_level`은 특정 method가 아니라 모든 control method evaluation에 적용된다. 의도치 않은 대량 log를 피하려면 state를 활성화하기 전에 method path가 설정되어 있는지 확인해야 한다.

"disable"
  Disable the method tracing feature.

"enable"
  Enable the method tracing feature.
  
  ACPICA debugging messages matching "trace_debug_layer/trace_debug_level"
  during any method execution will be logged.

"method"
  Enable the method tracing feature.

  ACPICA debugging messages matching "trace_debug_layer/trace_debug_level"
  during method execution of "trace_method_name" will be logged.

"method-once"
  Enable the method tracing feature.

  ACPICA debugging messages matching "trace_debug_layer/trace_debug_level"
  during method execution of "trace_method_name" will be logged only once.

"opcode"
  Enable the method tracing feature.

  ACPICA debugging messages matching "trace_debug_layer/trace_debug_level"
  during method/opcode execution of "trace_method_name" will be logged.

"opcode-once"
  Enable the method tracing feature.

  ACPICA debugging messages matching "trace_debug_layer/trace_debug_level"
  during method/opcode execution of "trace_method_name" will be logged only
  once.

Note that, the difference between the "enable" and other feature
enabling options are:

1. When "enable" is specified, since
   "trace_debug_layer/trace_debug_level" shall apply to all control
   method evaluations, after configuring "trace_state" to "enable",
   "trace_method_name" will be reset to NULL.
2. When "method/opcode" is specified, if
   "trace_method_name" is NULL when "trace_state" is configured to
   these options, the "trace_debug_layer/trace_debug_level" will
   apply to all control method evaluations.