Re: [igt-dev] [PATCH i-g-t 3/3] lib: Enable extra kernel logs for audio debug

[Daniel Vetter <daniel@ffwll.ch>]

On Tue, Apr 02, 2019 at 05:45:35PM -0700, Ashutosh Dixit wrote:
> For debug of audio issues in power management and driver reload tests,
> additional kernel logs may be useful, both in dmesg as well as
> ftrace. Add the infrastructure to generate these logs and enable these
> logs for selected tests.
> 
> At present igt_runner and other CI infrastructure does not capture the
> ftrace buffer. Therefore, to avoid changes to igt_runner and the CI
> infrastructure the ftrace buffer is dumped to stdout at the end of
> each test.
> 
> v5: use ARRAY_SIZE(), s/audio_klog/audio_dmesg_and_ftrace/
> v4: remove system() calls, dump audio kernel logs from igt_fixture
> v2, v3: versions to fix CI
> 
> Cc: Jani Nikula <jani.nikula@linux.intel.com>
> Signed-off-by: Ashutosh Dixit <ashutosh.dixit@intel.com>

I think it would be good to integrate this a bit tigther into igt
infrastructure:
- use an exit handler to do the cleanup, that will also handle aborts and
  stuff like that
- only dump the ftrace buffer if we fail a subtest, and dump it
  immediately. Similar to how we dump the entire igt debug crash recorder
  already. One issue could be tests where the test passes, but we get some
  kernel backtrace and we'd still like to see an ftrace. Maybe we need to
  pull the tainting checks into subtest exit code (shared with the
  runner).
- enable useful ftrace debug stuff by default on all tests. If it's
  useful, it's probably useful in unexpected places too. Of course this
  means we need to check to make sure those events are present first
  before we try to enable them.

In general I think this is really good, there's lots of bugs and issue
that would benefit from capturing some ftrace of what's been going on
right before the test blew up.
-Daniel

> ---
>  lib/igt_audio.c               | 57 +++++++++++++++++++++++++++++++++++
>  lib/igt_audio.h               |  2 ++
>  tests/i915/i915_module_load.c |  8 +++++
>  tests/i915/i915_pm_rpm.c      |  8 ++++-
>  tests/i915/i915_suspend.c     |  8 +++--
>  5 files changed, 80 insertions(+), 3 deletions(-)
> 
> diff --git a/lib/igt_audio.c b/lib/igt_audio.c
> index a0592d53..89892ca6 100644
> --- a/lib/igt_audio.c
> +++ b/lib/igt_audio.c
> @@ -31,6 +31,9 @@
>  
>  #include "igt_audio.h"
>  #include "igt_core.h"
> +#include "igt_debugfs.h"
> +#include "igt_ftrace.h"
> +#include "drmtest.h"
>  
>  #define FREQS_MAX	8
>  
> @@ -323,3 +326,57 @@ bool audio_signal_detect(struct audio_signal *signal, int channels,
>  
>  	return true;
>  }
> +
> +static const char *audio_dmesg_en[] = {
> +	"file sound/* +p",
> +};
> +
> +static const char *audio_dmesg_dis[] = {
> +	"file sound/* -p",
> +};
> +
> +static const char *audio_ftr[] = {
> +	"events/sst/enable",
> +	"events/intel-sst/enable",
> +	"events/asoc/enable",
> +	"events/i2c/enable",
> +	"events/hda/enable",
> +	"events/hda_controller/enable",
> +	"events/hda_intel/enable",
> +};
> +
> +static void igt_enable_audio_dmesg(void)
> +{
> +	igt_set_dynamic_debug(audio_dmesg_en, ARRAY_SIZE(audio_dmesg_en));
> +}
> +
> +static void igt_disable_audio_dmesg(void)
> +{
> +	igt_set_dynamic_debug(audio_dmesg_dis, ARRAY_SIZE(audio_dmesg_dis));
> +}
> +
> +static void igt_enable_audio_ftrace(void)
> +{
> +	igt_ftrace_set_events(audio_ftr, ARRAY_SIZE(audio_ftr), true);
> +	__igt_ftrace_enable("nop", NULL);
> +}
> +
> +static void igt_disable_audio_ftrace(void)
> +{
> +	igt_ftrace_disable();
> +	igt_ftrace_set_events(audio_ftr, ARRAY_SIZE(audio_ftr), false);
> +	igt_ftrace_dump("Ftrace output");
> +	igt_ftrace_clear();
> +}
> +
> +void igt_enable_audio_dmesg_and_ftrace(void)
> +{
> +	igt_enable_audio_dmesg();
> +	igt_enable_audio_ftrace();
> +}
> +
> +void igt_disable_audio_dmesg_and_ftrace(void)
> +{
> +	igt_disable_audio_ftrace();
> +	igt_disable_audio_dmesg();
> +}
> diff --git a/lib/igt_audio.h b/lib/igt_audio.h
> index b3b658a4..138682d9 100644
> --- a/lib/igt_audio.h
> +++ b/lib/igt_audio.h
> @@ -40,5 +40,7 @@ void audio_signal_clean(struct audio_signal *signal);
>  void audio_signal_fill(struct audio_signal *signal, short *buffer, int frames);
>  bool audio_signal_detect(struct audio_signal *signal, int channels,
>  			 int sampling_rate, short *buffer, int frames);
> +void igt_enable_audio_dmesg_and_ftrace(void);
> +void igt_disable_audio_dmesg_and_ftrace(void);
>  
>  #endif
> diff --git a/tests/i915/i915_module_load.c b/tests/i915/i915_module_load.c
> index 7fe83520..3bddeafd 100644
> --- a/tests/i915/i915_module_load.c
> +++ b/tests/i915/i915_module_load.c
> @@ -326,6 +326,10 @@ hda_dynamic_debug(bool enable)
>  
>  igt_main
>  {
> +	igt_fixture {
> +		igt_enable_audio_dmesg_and_ftrace();
> +	}
> +
>  	igt_subtest("reload") {
>  		int load_error;
>  
> @@ -365,5 +369,9 @@ igt_main
>  		/* inject_fault() leaves the module unloaded */
>  	}
>  
> +	igt_fixture {
> +		igt_disable_audio_dmesg_and_ftrace();
> +	}
> +
>  	/* Subtests should unload the module themselves if they use modparams */
>  }
> diff --git a/tests/i915/i915_pm_rpm.c b/tests/i915/i915_pm_rpm.c
> index a2c9d0ed..758ba368 100644
> --- a/tests/i915/i915_pm_rpm.c
> +++ b/tests/i915/i915_pm_rpm.c
> @@ -1978,8 +1978,10 @@ int main(int argc, char *argv[])
>  	/* Skip instead of failing in case the machine is not prepared to reach
>  	 * PC8+. We don't want bug reports from cases where the machine is just
>  	 * not properly configured. */
> -	igt_fixture
> +	igt_fixture {
> +		igt_enable_audio_dmesg_and_ftrace();
>  		igt_require(setup_environment());
> +	}
>  
>  	if (stay)
>  		igt_subtest("stay")
> @@ -2121,5 +2123,9 @@ int main(int argc, char *argv[])
>  		igt_i915_driver_unload();
>  	}
>  
> +	igt_fixture {
> +		igt_disable_audio_dmesg_and_ftrace();
> +	}
> +
>  	igt_exit();
>  }
> diff --git a/tests/i915/i915_suspend.c b/tests/i915/i915_suspend.c
> index 17c68cc1..2241ff8d 100644
> --- a/tests/i915/i915_suspend.c
> +++ b/tests/i915/i915_suspend.c
> @@ -207,8 +207,10 @@ igt_main
>  {
>  	igt_skip_on_simulation();
>  
> -	igt_fixture
> +	igt_fixture {
>  		fd = drm_open_driver(DRIVER_INTEL);
> +		igt_enable_audio_dmesg_and_ftrace();
> +	}
>  
>  	igt_subtest("fence-restore-tiled2untiled")
>  		test_fence_restore(fd, true, false);
> @@ -243,6 +245,8 @@ igt_main
>  	igt_subtest("forcewake-hibernate")
>  		test_forcewake(fd, true);
>  
> -	igt_fixture
> +	igt_fixture {
> +		igt_disable_audio_dmesg_and_ftrace();
>  		close(fd);
> +	}
>  }
> -- 
> 2.21.0
> 
> _______________________________________________
> igt-dev mailing list
> igt-dev@lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/igt-dev

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev