Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
45 changes: 31 additions & 14 deletions tools/logger/convert.c
Original file line number Diff line number Diff line change
Expand Up @@ -279,18 +279,37 @@ static double to_usecs(uint64_t time)
return (double)time / global_config->clock;
}

/** Justified timestamp width for printf format string */
static unsigned int timestamp_width(unsigned int precision)
{
/* 64bits yields less than 20 digits precision. As reported by
* gcc 9.3, this avoids a very long precision causing snprintf()
* to truncate time_fmt
*/
assert(precision >= 0 && precision < 20);
/*
* 12 digits for units is enough for 1M seconds = 11 days which
* should be enough for most test runs.
*
* Add 1 for the comma when there is one.
*/
return 12 + (precision > 0 ? 1 : 0) + precision;
}

Comment on lines +283 to +298
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Previous version is capable to skip timestamp printing to allow easily use diff tool on logs, this commit removes this possibility

Copy link
Collaborator Author

@marc-hb marc-hb Apr 26, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great catch, thanks @ktrzcinx for the review. Fixed in 6c1a4cd.

PS: any idea why QB never tested 6c8333d ? (PTS-31119)

EDIT: https://sof-ci.01.org/sof-pr-viewer/#/build/PR4086/build6358153 is all green

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

QB fails because of linking error in build with codec adapter:
src/audio/codec_adapter/codec/cadence.c.o:(.data+0x2c): undefined reference to "cadence_api_function"

So it looks unrelated to this PR

static inline void print_table_header(void)
{
FILE *out_fd = global_config->out_fd;
int hide_location = global_config->hide_location;
int time_precision = global_config->time_precision;
char time_fmt[32];

if (time_precision >= 0) {
snprintf(time_fmt, sizeof(time_fmt), "%%%ds %%%ds ",
time_precision + 12, time_precision + 12);
fprintf(out_fd, time_fmt, "TIMESTAMP", "DELTA");
if (global_config->time_precision >= 0) {
const unsigned int ts_width =
timestamp_width(global_config->time_precision);
snprintf(time_fmt, sizeof(time_fmt), "%%-%ds(us)%%%ds ",
ts_width, ts_width);
fprintf(out_fd, time_fmt, " TIMESTAMP", "DELTA");
}

fprintf(out_fd, "%2s %-18s ", "C#", "COMPONENT");
if (!hide_location)
fprintf(out_fd, "%-29s ", "LOCATION");
Expand Down Expand Up @@ -442,16 +461,13 @@ static void print_entry_params(const struct log_entry_header *dma_log,
format_file_name(entry->file_name, raw_output),
entry->header.line_idx);
} else {
/* timestamp */
/* 64bits yields less than 20 digits precision. As
* reported by gcc 9.3, this avoids a very long
* precision causing snprintf() to truncate time_fmt
*/
if (time_precision >= 0 && time_precision < 20) {
if (time_precision >= 0) {
const unsigned int ts_width = timestamp_width(time_precision);

snprintf(time_fmt, sizeof(time_fmt),
"%%s[%%%d.%df] (%%%d.%df)%%s ",
time_precision + 10, time_precision,
time_precision + 10, time_precision);
ts_width, time_precision, ts_width, time_precision);

fprintf(out_fd, time_fmt,
use_colors ? KGRN : "",
to_usecs(dma_log->timestamp - timestamp_origin), dt,
Expand Down Expand Up @@ -628,7 +644,8 @@ static int fetch_entry(const struct log_entry_header *dma_log, uint64_t *last_ti
goto out;
}
if (ret != size)
log_err("Partial read of %u bytes of %lu.\n", ret, size);
log_err("Partial read of %u bytes of %lu, reading more\n",
ret, size);
}
}

Expand Down
14 changes: 9 additions & 5 deletions tools/logger/logger.c
Original file line number Diff line number Diff line change
Expand Up @@ -31,10 +31,13 @@ static const char *debugfs[] = {
"hda", "pp", "dsp",
};

/** See PLATFORM_DEFAULT_CLOCK in the firmware code. */
static const float DEFAULT_CLOCK_MHZ = 19.2;

static void usage(void)
{
fprintf(stdout, "Usage %s <option(s)> <file(s)>\n", APP_NAME);
fprintf(stdout, "%s:\t \t\t\tDisplay mailbox contents\n", APP_NAME);
fprintf(stdout, "%s:\t \t\t\tDisplay mailbox or DMA trace contents\n", APP_NAME);
fprintf(stdout, "%s:\t -i infile -o outfile\tDump infile contents "
"to outfile\n", APP_NAME);
fprintf(stdout, "%s:\t -l *.ldc_file\t\t*.ldc files generated by smex\n",
Expand All @@ -44,11 +47,12 @@ static void usage(void)
"with ver_file file\n", APP_NAME);
fprintf(stdout, "%s:\t -n\t\t\tDisable checking firmware version\n",
APP_NAME);
fprintf(stdout, "%s:\t -c clock\t\tSet timestamp clock in MHz\n",
APP_NAME);
fprintf(stdout, "%s:\t -c clock\t\tSet timestamp clock in MHz, %.2f MHz by default\n",
APP_NAME, DEFAULT_CLOCK_MHZ);
fprintf(stdout, "%s:\t -s state_name\t\tTake a snapshot of state\n",
APP_NAME);
fprintf(stdout, "%s:\t -t\t\t\tDisplay trace data\n", APP_NAME);
fprintf(stdout, "%s:\t -t\t\t\tDMA 'trace' stream instead of 'etrace' error mailbox\n",
APP_NAME);
fprintf(stdout, "%s:\t -u baud\t\tInput data from a UART\n", APP_NAME);
fprintf(stdout, "%s:\t -r\t\t\tLess formatted output for "
"chained log processors\n",
Expand Down Expand Up @@ -175,7 +179,7 @@ int main(int argc, char *argv[])
int opt, ret = 0;

config.trace = 0;
config.clock = 19.2;
config.clock = DEFAULT_CLOCK_MHZ;
config.in_file = NULL;
config.out_file = NULL;
config.out_fd = NULL;
Expand Down