ACK: [PATCH] s3 + klog: make log scanning more robust for S3 (LP: #1522292)

[Alex Hung]

On 12/04/2015 03:43 AM, Colin King wrote:
> From: Colin Ian King <colin.king at canonical.com>
>
> We sometimes get klog messages not appearing in the kernel log
> when written by userspace via /dev/kmsg on recent kernels. I've
> not yet figured out why that is, but a simple workaround for
> the moment is to make the kernel log scanning for the FWTS S3
> going to suspend marker is to check for other messages fwts
> inserts into the log since at least one of these messages always
> ends up in the log.
>
> Also, add a kernel log priority level and fwts: prefix to all
> messages from fwts that get written to /dev/ksmg for easier
> identification.
>
> Signed-off-by: Colin Ian King <colin.king at canonical.com>
> ---
>   src/acpi/s3/s3.c        | 12 ++++++++----
>   src/lib/src/fwts_klog.c |  3 ++-
>   2 files changed, 10 insertions(+), 5 deletions(-)
>
> diff --git a/src/acpi/s3/s3.c b/src/acpi/s3/s3.c
> index 2af93dc..8e224cf 100644
> --- a/src/acpi/s3/s3.c
> +++ b/src/acpi/s3/s3.c
> @@ -103,10 +103,11 @@ static int wrap_sysfs_do_suspend(fwts_pm_method_vars *fwts_settings,
>   	int status;
>
>   	FWTS_UNUSED(str);
> +	(void)fwts_klog_write(fwts_settings->fw, FWTS_SUSPEND "\n");
>   	fwts_progress_message(fwts_settings->fw, percent, "(Suspending)");
> -	time(&(fwts_settings->t_start));
> -	(void)fwts_klog_write(fwts_settings->fw, "Starting fwts suspend\n");
>   	(void)fwts_klog_write(fwts_settings->fw, FWTS_SUSPEND "\n");
> +	(void)fwts_klog_write(fwts_settings->fw, "Starting fwts suspend\n");
> +	time(&(fwts_settings->t_start));
>   	status = fwts_sysfs_do_suspend(fwts_settings, s3_hybrid);
>   	(void)fwts_klog_write(fwts_settings->fw, FWTS_RESUME "\n");
>   	(void)fwts_klog_write(fwts_settings->fw, "Finished fwts resume\n");
> @@ -125,10 +126,12 @@ static int wrap_pmutils_do_suspend(fwts_pm_method_vars *fwts_settings,
>   {
>   	int status;
>
> +	(void)fwts_klog_write(fwts_settings->fw, FWTS_SUSPEND "\n");
>   	fwts_progress_message(fwts_settings->fw, percent, "(Suspending)");
> -	time(&(fwts_settings->t_start));
> +	(void)fwts_klog_write(fwts_settings->fw, FWTS_SUSPEND "\n");
>   	(void)fwts_klog_write(fwts_settings->fw, "Starting fwts suspend\n");
>   	(void)fwts_klog_write(fwts_settings->fw, FWTS_SUSPEND "\n");
> +	time(&(fwts_settings->t_start));
>   	(void)fwts_exec(command, &status);
>   	(void)fwts_klog_write(fwts_settings->fw, FWTS_RESUME "\n");
>   	(void)fwts_klog_write(fwts_settings->fw, "Finished fwts resume\n");
> @@ -318,7 +321,8 @@ static int s3_scan_times(
>
>   		/* Get log time stamp */
>   		sscanf(bracket + 1, "%lf", &ts);
> -		if (strstr(txt, FWTS_SUSPEND)) {
> +		if (strstr(txt, FWTS_SUSPEND) ||
> +		    strstr(txt, "Starting fwts suspend")) {
>   			s3_suspend_start = ts;
>   			continue;
>   		}
> diff --git a/src/lib/src/fwts_klog.c b/src/lib/src/fwts_klog.c
> index c164396..214117f 100644
> --- a/src/lib/src/fwts_klog.c
> +++ b/src/lib/src/fwts_klog.c
> @@ -547,7 +547,8 @@ int fwts_klog_write(fwts_framework *fw, const char *msg)
>   		return FWTS_ERROR;
>   	}
>
> -	fprintf(fp, "%s", msg);
> +	fprintf(fp, "<7>fwts: %s", msg);
> +	fflush(fp);
>   	fclose(fp);
>
>   	return FWTS_OK;
>

Acked-by: Alex Hung <alex.hung at canonical.com>