[i-g-t,1/3] lib/core: Add optional reason for timeout failure
diff mbox

Message ID 1438968558-1036-1-git-send-email-daniel.vetter@ffwll.ch
State New
Headers show

Commit Message

Daniel Vetter Aug. 7, 2015, 5:29 p.m. UTC
"Timed out" isn't a terribly informative message, allow users to set
something more informative. Inspired by a request from Jesse.

Cc: Jesse Barnes <jbarnes@virtuousgeek.org>
Signed-off-by: Daniel Vetter <daniel.vetter@intel.com>
---
 lib/igt_core.c          | 12 ++++++++++--
 lib/igt_core.h          |  3 ++-
 lib/igt_debugfs.c       |  4 ++--
 lib/tests/igt_timeout.c |  2 +-
 tests/kms_flip.c        |  4 ++--
 5 files changed, 17 insertions(+), 8 deletions(-)

Comments

Jesse Barnes Aug. 7, 2015, 6:10 p.m. UTC | #1
On 08/07/2015 10:29 AM, Daniel Vetter wrote:
> "Timed out" isn't a terribly informative message, allow users to set
> something more informative. Inspired by a request from Jesse.
> 
> Cc: Jesse Barnes <jbarnes@virtuousgeek.org>
> Signed-off-by: Daniel Vetter <daniel.vetter@intel.com>
> ---
>  lib/igt_core.c          | 12 ++++++++++--
>  lib/igt_core.h          |  3 ++-
>  lib/igt_debugfs.c       |  4 ++--
>  lib/tests/igt_timeout.c |  2 +-
>  tests/kms_flip.c        |  4 ++--
>  5 files changed, 17 insertions(+), 8 deletions(-)
> 
> diff --git a/lib/igt_core.c b/lib/igt_core.c
> index af3d87316857..e2c2502bd147 100644
> --- a/lib/igt_core.c
> +++ b/lib/igt_core.c
> @@ -1748,9 +1748,13 @@ out:
>  	free(line);
>  }
>  
> +static const char *timeout_op;
>  static void igt_alarm_handler(int signal)
>  {
> -	igt_info("Timed out\n");
> +	if (timeout_op)
> +		igt_info("Timed out: %s\n", timeout_op);
> +	else
> +		igt_info("Timed out\n");
>  
>  	/* exit with failure status */
>  	igt_fail(IGT_EXIT_FAILURE);
> @@ -1759,6 +1763,7 @@ static void igt_alarm_handler(int signal)
>  /**
>   * igt_set_timeout:
>   * @seconds: number of seconds before timeout
> + * @op: Optional string to explain what operation has timed out in the debug log
>   *
>   * Fail a test and exit with #IGT_EXIT_FAILURE status after the specified
>   * number of seconds have elapsed. If the current test has subtests and the
> @@ -1768,7 +1773,8 @@ static void igt_alarm_handler(int signal)
>   * Any previous timer is cancelled and no timeout is scheduled if @seconds is
>   * zero.
>   */
> -void igt_set_timeout(unsigned int seconds)
> +void igt_set_timeout(unsigned int seconds,
> +		     const char *op)
>  {
>  	struct sigaction sa;
>  
> @@ -1776,6 +1782,8 @@ void igt_set_timeout(unsigned int seconds)
>  	sigemptyset(&sa.sa_mask);
>  	sa.sa_flags = 0;
>  
> +	timeout_op = op;
> +
>  	if (seconds == 0)
>  		sigaction(SIGALRM, NULL, NULL);
>  	else
> diff --git a/lib/igt_core.h b/lib/igt_core.h
> index 83eac02b28bf..1a324ee85514 100644
> --- a/lib/igt_core.h
> +++ b/lib/igt_core.h
> @@ -732,7 +732,8 @@ extern enum igt_log_level igt_log_level;
>  	} while (0)
>  
>  
> -void igt_set_timeout(unsigned int seconds);
> +void igt_set_timeout(unsigned int seconds,
> +		     const char *op);
>  
>  FILE *__igt_fopen_data(const char* igt_srcdir, const char* igt_datadir,
>  		       const char* filename);
> diff --git a/lib/igt_debugfs.c b/lib/igt_debugfs.c
> index 568154ac0e80..6180a2aa56db 100644
> --- a/lib/igt_debugfs.c
> +++ b/lib/igt_debugfs.c
> @@ -463,9 +463,9 @@ static bool read_one_crc(igt_pipe_crc_t *pipe_crc, igt_crc_t *out)
>  	ssize_t bytes_read;
>  	char buf[pipe_crc->buffer_len];
>  
> -	igt_set_timeout(5);
> +	igt_set_timeout(5, "CRC reading");
>  	bytes_read = read(pipe_crc->crc_fd, &buf, pipe_crc->line_len);
> -	igt_set_timeout(0);
> +	igt_set_timeout(0, NULL);
>  
>  	igt_assert_eq(bytes_read, pipe_crc->line_len);
>  	buf[bytes_read] = '\0';
> diff --git a/lib/tests/igt_timeout.c b/lib/tests/igt_timeout.c
> index 8affa61f3d79..d228041d493b 100644
> --- a/lib/tests/igt_timeout.c
> +++ b/lib/tests/igt_timeout.c
> @@ -3,6 +3,6 @@
>  
>  igt_simple_main
>  {
> -	igt_set_timeout(1);
> +	igt_set_timeout(1, "Testcase");
>  	sleep(5);
>  }
> diff --git a/tests/kms_flip.c b/tests/kms_flip.c
> index 25c924305c32..214cd696fd2f 100644
> --- a/tests/kms_flip.c
> +++ b/tests/kms_flip.c
> @@ -1614,9 +1614,9 @@ static void test_nonblocking_read(int in)
>  	}
>  	igt_require(ret != -1);
>  
> -	igt_set_timeout(5);
> +	igt_set_timeout(5, "Nonblocking DRM fd reading");
>  	ret = read(fd, buffer, sizeof(buffer));
> -	igt_set_timeout(0);
> +	igt_set_timeout(0, NULL);
>  	igt_assert_eq(ret, -1);
>  	igt_assert_eq(errno, EAGAIN);
>  
> 

Reviewed-by: Jesse Barnes <jbarnes@virtuousgeek.org>

The earlier version worked like a charm.

Thanks,
Jesse
Daniel Vetter Aug. 12, 2015, 12:47 p.m. UTC | #2
On Fri, Aug 07, 2015 at 11:10:22AM -0700, Jesse Barnes wrote:
> On 08/07/2015 10:29 AM, Daniel Vetter wrote:
> > "Timed out" isn't a terribly informative message, allow users to set
> > something more informative. Inspired by a request from Jesse.
> > 
> > Cc: Jesse Barnes <jbarnes@virtuousgeek.org>
> > Signed-off-by: Daniel Vetter <daniel.vetter@intel.com>
> > ---
> >  lib/igt_core.c          | 12 ++++++++++--
> >  lib/igt_core.h          |  3 ++-
> >  lib/igt_debugfs.c       |  4 ++--
> >  lib/tests/igt_timeout.c |  2 +-
> >  tests/kms_flip.c        |  4 ++--
> >  5 files changed, 17 insertions(+), 8 deletions(-)
> > 
> > diff --git a/lib/igt_core.c b/lib/igt_core.c
> > index af3d87316857..e2c2502bd147 100644
> > --- a/lib/igt_core.c
> > +++ b/lib/igt_core.c
> > @@ -1748,9 +1748,13 @@ out:
> >  	free(line);
> >  }
> >  
> > +static const char *timeout_op;
> >  static void igt_alarm_handler(int signal)
> >  {
> > -	igt_info("Timed out\n");
> > +	if (timeout_op)
> > +		igt_info("Timed out: %s\n", timeout_op);
> > +	else
> > +		igt_info("Timed out\n");
> >  
> >  	/* exit with failure status */
> >  	igt_fail(IGT_EXIT_FAILURE);
> > @@ -1759,6 +1763,7 @@ static void igt_alarm_handler(int signal)
> >  /**
> >   * igt_set_timeout:
> >   * @seconds: number of seconds before timeout
> > + * @op: Optional string to explain what operation has timed out in the debug log
> >   *
> >   * Fail a test and exit with #IGT_EXIT_FAILURE status after the specified
> >   * number of seconds have elapsed. If the current test has subtests and the
> > @@ -1768,7 +1773,8 @@ static void igt_alarm_handler(int signal)
> >   * Any previous timer is cancelled and no timeout is scheduled if @seconds is
> >   * zero.
> >   */
> > -void igt_set_timeout(unsigned int seconds)
> > +void igt_set_timeout(unsigned int seconds,
> > +		     const char *op)
> >  {
> >  	struct sigaction sa;
> >  
> > @@ -1776,6 +1782,8 @@ void igt_set_timeout(unsigned int seconds)
> >  	sigemptyset(&sa.sa_mask);
> >  	sa.sa_flags = 0;
> >  
> > +	timeout_op = op;
> > +
> >  	if (seconds == 0)
> >  		sigaction(SIGALRM, NULL, NULL);
> >  	else
> > diff --git a/lib/igt_core.h b/lib/igt_core.h
> > index 83eac02b28bf..1a324ee85514 100644
> > --- a/lib/igt_core.h
> > +++ b/lib/igt_core.h
> > @@ -732,7 +732,8 @@ extern enum igt_log_level igt_log_level;
> >  	} while (0)
> >  
> >  
> > -void igt_set_timeout(unsigned int seconds);
> > +void igt_set_timeout(unsigned int seconds,
> > +		     const char *op);
> >  
> >  FILE *__igt_fopen_data(const char* igt_srcdir, const char* igt_datadir,
> >  		       const char* filename);
> > diff --git a/lib/igt_debugfs.c b/lib/igt_debugfs.c
> > index 568154ac0e80..6180a2aa56db 100644
> > --- a/lib/igt_debugfs.c
> > +++ b/lib/igt_debugfs.c
> > @@ -463,9 +463,9 @@ static bool read_one_crc(igt_pipe_crc_t *pipe_crc, igt_crc_t *out)
> >  	ssize_t bytes_read;
> >  	char buf[pipe_crc->buffer_len];
> >  
> > -	igt_set_timeout(5);
> > +	igt_set_timeout(5, "CRC reading");
> >  	bytes_read = read(pipe_crc->crc_fd, &buf, pipe_crc->line_len);
> > -	igt_set_timeout(0);
> > +	igt_set_timeout(0, NULL);
> >  
> >  	igt_assert_eq(bytes_read, pipe_crc->line_len);
> >  	buf[bytes_read] = '\0';
> > diff --git a/lib/tests/igt_timeout.c b/lib/tests/igt_timeout.c
> > index 8affa61f3d79..d228041d493b 100644
> > --- a/lib/tests/igt_timeout.c
> > +++ b/lib/tests/igt_timeout.c
> > @@ -3,6 +3,6 @@
> >  
> >  igt_simple_main
> >  {
> > -	igt_set_timeout(1);
> > +	igt_set_timeout(1, "Testcase");
> >  	sleep(5);
> >  }
> > diff --git a/tests/kms_flip.c b/tests/kms_flip.c
> > index 25c924305c32..214cd696fd2f 100644
> > --- a/tests/kms_flip.c
> > +++ b/tests/kms_flip.c
> > @@ -1614,9 +1614,9 @@ static void test_nonblocking_read(int in)
> >  	}
> >  	igt_require(ret != -1);
> >  
> > -	igt_set_timeout(5);
> > +	igt_set_timeout(5, "Nonblocking DRM fd reading");
> >  	ret = read(fd, buffer, sizeof(buffer));
> > -	igt_set_timeout(0);
> > +	igt_set_timeout(0, NULL);
> >  	igt_assert_eq(ret, -1);
> >  	igt_assert_eq(errno, EAGAIN);
> >  
> > 
> 
> Reviewed-by: Jesse Barnes <jbarnes@virtuousgeek.org>

Thanks for the review, pushed this patch + the other two + David's patch
to test NO_ZEROMAP to fix the gem_ctx_param_basic regression.
-Daniel

> 
> The earlier version worked like a charm.
> 
> Thanks,
> Jesse

Patch
diff mbox

diff --git a/lib/igt_core.c b/lib/igt_core.c
index af3d87316857..e2c2502bd147 100644
--- a/lib/igt_core.c
+++ b/lib/igt_core.c
@@ -1748,9 +1748,13 @@  out:
 	free(line);
 }
 
+static const char *timeout_op;
 static void igt_alarm_handler(int signal)
 {
-	igt_info("Timed out\n");
+	if (timeout_op)
+		igt_info("Timed out: %s\n", timeout_op);
+	else
+		igt_info("Timed out\n");
 
 	/* exit with failure status */
 	igt_fail(IGT_EXIT_FAILURE);
@@ -1759,6 +1763,7 @@  static void igt_alarm_handler(int signal)
 /**
  * igt_set_timeout:
  * @seconds: number of seconds before timeout
+ * @op: Optional string to explain what operation has timed out in the debug log
  *
  * Fail a test and exit with #IGT_EXIT_FAILURE status after the specified
  * number of seconds have elapsed. If the current test has subtests and the
@@ -1768,7 +1773,8 @@  static void igt_alarm_handler(int signal)
  * Any previous timer is cancelled and no timeout is scheduled if @seconds is
  * zero.
  */
-void igt_set_timeout(unsigned int seconds)
+void igt_set_timeout(unsigned int seconds,
+		     const char *op)
 {
 	struct sigaction sa;
 
@@ -1776,6 +1782,8 @@  void igt_set_timeout(unsigned int seconds)
 	sigemptyset(&sa.sa_mask);
 	sa.sa_flags = 0;
 
+	timeout_op = op;
+
 	if (seconds == 0)
 		sigaction(SIGALRM, NULL, NULL);
 	else
diff --git a/lib/igt_core.h b/lib/igt_core.h
index 83eac02b28bf..1a324ee85514 100644
--- a/lib/igt_core.h
+++ b/lib/igt_core.h
@@ -732,7 +732,8 @@  extern enum igt_log_level igt_log_level;
 	} while (0)
 
 
-void igt_set_timeout(unsigned int seconds);
+void igt_set_timeout(unsigned int seconds,
+		     const char *op);
 
 FILE *__igt_fopen_data(const char* igt_srcdir, const char* igt_datadir,
 		       const char* filename);
diff --git a/lib/igt_debugfs.c b/lib/igt_debugfs.c
index 568154ac0e80..6180a2aa56db 100644
--- a/lib/igt_debugfs.c
+++ b/lib/igt_debugfs.c
@@ -463,9 +463,9 @@  static bool read_one_crc(igt_pipe_crc_t *pipe_crc, igt_crc_t *out)
 	ssize_t bytes_read;
 	char buf[pipe_crc->buffer_len];
 
-	igt_set_timeout(5);
+	igt_set_timeout(5, "CRC reading");
 	bytes_read = read(pipe_crc->crc_fd, &buf, pipe_crc->line_len);
-	igt_set_timeout(0);
+	igt_set_timeout(0, NULL);
 
 	igt_assert_eq(bytes_read, pipe_crc->line_len);
 	buf[bytes_read] = '\0';
diff --git a/lib/tests/igt_timeout.c b/lib/tests/igt_timeout.c
index 8affa61f3d79..d228041d493b 100644
--- a/lib/tests/igt_timeout.c
+++ b/lib/tests/igt_timeout.c
@@ -3,6 +3,6 @@ 
 
 igt_simple_main
 {
-	igt_set_timeout(1);
+	igt_set_timeout(1, "Testcase");
 	sleep(5);
 }
diff --git a/tests/kms_flip.c b/tests/kms_flip.c
index 25c924305c32..214cd696fd2f 100644
--- a/tests/kms_flip.c
+++ b/tests/kms_flip.c
@@ -1614,9 +1614,9 @@  static void test_nonblocking_read(int in)
 	}
 	igt_require(ret != -1);
 
-	igt_set_timeout(5);
+	igt_set_timeout(5, "Nonblocking DRM fd reading");
 	ret = read(fd, buffer, sizeof(buffer));
-	igt_set_timeout(0);
+	igt_set_timeout(0, NULL);
 	igt_assert_eq(ret, -1);
 	igt_assert_eq(errno, EAGAIN);