horaedb icon indicating copy to clipboard operation
horaedb copied to clipboard

The `mysql server` error log cannot be located to the exact location

Open dust1 opened this issue 3 years ago • 4 comments

Description

When I was debugging, I found that the stack information of the exception often could not locate the real exception occurrence point.

Proposal

Additional context

when i debugging this sql:

CREATE TABLE d222 (
    name string TAG,
    value double NOT NULL,
    t timestamp NOT NULL TIMESTAMP KEY
) ENGINE=Analytic;

the error log only goes to the place where the last level exception was thrown.

2022-07-24 17:33:22.750 ERRO [server/src/mysql/worker.rs:117] Mysql service Failed to handle sql, err: Failed to create plan, query:CREATE TABLE d222 (
    name string TAG,
    value double NOT NULL,
    t timestamp NOT NULL TIMESTAMP KEY
) ENGINE=Analytic, err:Failed to create plan, err:Table must contain timestamp constraint
2022-07-24 17:33:22.750 ERRO [server/src/mysql/worker.rs:95] MysqlWorker on_query failed. err:Failed to handle sql:CREATE TABLE d222 (
    name string TAG,
    value double NOT NULL,
    t timestamp NOT NULL TIMESTAMP KEY
) ENGINE=Analytic, err:Failed to create plan, query:CREATE TABLE d222 (
    name string TAG,
    value double NOT NULL,
    t timestamp NOT NULL TIMESTAMP KEY
) ENGINE=Analytic, err:Failed to create plan, err:Table must contain timestamp constraint

It only goes to server/src/mysql/worker.rs, but I know where the exception really happens is not here.

dust1 avatar Jul 24 '22 09:07 dust1

In CeresDB, we use snafu for error handling, if you want backtrace, just add it in Error enum like this:

https://github.com/CeresDB/ceresdb/blob/a030c06fa2290139938bcd14b16eab3d0a60597c/server/src/context.rs#L14

jiacai2050 avatar Jul 25 '22 08:07 jiacai2050

got it! I will fix it later. thanks.

dust1 avatar Jul 25 '22 08:07 dust1

The two locations (server/src/mysql/worker.rs:117 and server/src/mysql/worker.rs:95) displayed in log are where we logging those errors (via error!). This is not very intuitive indeed.

In this case, I'll first search for Table must contain timestamp constraint as I guess it is the error description for the inner error. And I can get RequireTimestamp this error variant. Then I can search for it and find the actual place. This method works but it's not very convenient and robust.

The definition of RequireTimestamp is

    #[snafu(display("Table must contain timestamp constraint"))]
    RequireTimestamp,

which is just kind of constant literal. I.e. we choose not to include a concrete backtrace for this error variant. However according to snafu's guide it's recommended to include backtrace for leaf error:

The most common leaf error should always include a backtrace field.

So maybe we need a further discussion about how to define our error type. And I can think of another way that only captures a line number in the leaf error (like [server/src/mysql/worker.rs:117] from the log) instead of a "backtrace" which should be more lightweight.

waynexia avatar Jul 25 '22 08:07 waynexia

So maybe we need a further discussion about how to define our error type.

Actually, the style for definition of error type requires a backtrace for leaf error but this is implicit and maybe we should make it clear in our style guide.

And I can think of another way that only captures line number in the leaf error (like [server/src/mysql/worker.rs:117] from the log) instead of a "backtrace" which should be more lightweight.

I guess the information is not enough for troubleshootting if only a line number of leaf error is captured because maybe more than one call path will lead to the same error.

ShiKaiWi avatar Jul 26 '22 02:07 ShiKaiWi