Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve query runner error handling #642

Merged
merged 2 commits into from
Nov 28, 2024
Merged

Improve query runner error handling #642

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
b4f5295
Improve query runner error handling
seanlinsley Nov 26, 2024
5061be5
Wrap each query in a separate transaction
seanlinsley Nov 27, 2024
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
29 changes: 13 additions & 16 deletions runner/query_run.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@ func SetupQueryRunnerForAllServers(ctx context.Context, servers []*state.Server,

func run(ctx context.Context, server *state.Server, collectionOpts state.CollectionOpts, logger *util.Logger) {
for id, query := range server.QueryRuns {
var firstErr error
if !query.FinishedAt.IsZero() {
continue
}
Expand Down Expand Up @@ -83,31 +84,25 @@ func run(ctx context.Context, server *state.Server, collectionOpts state.Collect

// We don't include QueryMarkerSQL so query runs are reported separately in pganalyze
comment := fmt.Sprintf("/* pganalyze:no-alert,pganalyze-query-run:%d */ ", query.Id)
prefix := ""
result := ""
if query.Type == pganalyze_collector.QueryRunType_EXPLAIN {
prefix = "EXPLAIN (ANALYZE, VERBOSE, BUFFERS, FORMAT JSON) "
}

if query.Type == pganalyze_collector.QueryRunType_EXPLAIN {
// Rollback any changes the query may perform
db.ExecContext(ctx, postgres.QueryMarkerSQL+"BEGIN READ ONLY")

err = db.QueryRowContext(ctx, comment+prefix+query.QueryText).Scan(&result)
firstErr := err
sql := "BEGIN; EXPLAIN (ANALYZE, VERBOSE, BUFFERS, FORMAT JSON) " + comment + query.QueryText + "; ROLLBACK"
err = db.QueryRowContext(ctx, sql).Scan(&result)
firstErr = err

// Run EXPLAIN ANALYZE a second time to get a warm cache result
Copy link
Contributor

Choose a reason for hiding this comment

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

In #641 (comment), you mentioned that this is executed even if the firstErr is not nil for the case of first one failed with a timeout. However, even though the cause was a timeout, the second one will fail regardless:

pgaweb=# set statement_timeout = 1000;
SET
pgaweb=# begin read only;
BEGIN
pgaweb=*# select pg_sleep(2);
ERROR:  canceling statement due to statement timeout
pgaweb=!# select pg_sleep(0.5);
ERROR:  current transaction is aborted, commands ignored until end of transaction block

Meaning this code doesn't quite do what you want it to do. When the firstErr is not nil (for whatever the reason), this second query execution will always be ignored.

Copy link
Member Author

Choose a reason for hiding this comment

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

Good catch. Maybe the query text should contain BEGIN READ ONLY and COMMIT so each query is in its own transaction.

err = db.QueryRowContext(ctx, comment+prefix+query.QueryText).Scan(&result)
err = db.QueryRowContext(ctx, sql).Scan(&result)

// If the first run failed, run once more to get a warm cache result
// If the first run failed and the second run succeeded, run once more to get a warm cache result
if err == nil && firstErr != nil {
err = db.QueryRowContext(ctx, comment+prefix+query.QueryText).Scan(&result)
err = db.QueryRowContext(ctx, sql).Scan(&result)
}

// If the EXPLAIN ANALYZE timed out, capture a regular EXPLAIN instead
// If it timed out, capture a non-ANALYZE EXPLAIN instead
if err != nil && strings.Contains(err.Error(), "statement timeout") {
prefix = "EXPLAIN (VERBOSE, FORMAT JSON) "
err = db.QueryRowContext(ctx, comment+prefix+query.QueryText).Scan(&result)
sql = "BEGIN; EXPLAIN (VERBOSE, FORMAT JSON) " + comment + query.QueryText + "; ROLLBACK"
err = db.QueryRowContext(ctx, sql).Scan(&result)
}
} else {
err = errors.New("Unhandled query run type")
Expand All @@ -117,7 +112,9 @@ func run(ctx context.Context, server *state.Server, collectionOpts state.Collect
server.QueryRunsMutex.Lock()
server.QueryRuns[id].FinishedAt = time.Now()
server.QueryRuns[id].Result = result
if err != nil {
if firstErr != nil {
server.QueryRuns[id].Error = firstErr.Error()
} else if err != nil {
server.QueryRuns[id].Error = err.Error()
}
server.QueryRunsMutex.Unlock()
Expand Down
1 change: 1 addition & 0 deletions state/state.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -317,6 +317,7 @@ func MakeServer(config config.ServerConfig, testRun bool) *Server {
ActivityStateMutex: &sync.Mutex{},
CollectionStatusMutex: &sync.Mutex{},
SnapshotStream: make(chan []byte),
QueryRuns: make(map[int64]*QueryRun),
QueryRunsMutex: &sync.Mutex{},
LogParseMutex: &sync.RWMutex{},
}
Expand Down
Loading