diff --git a/src/auth/session.go b/src/auth/session.go index e8caf02f..eee43fc2 100644 --- a/src/auth/session.go +++ b/src/auth/session.go @@ -76,7 +76,10 @@ func CreateSession(ctx context.Context, conn *pgxpool.Pool, username string) (*m } _, err := conn.Exec(ctx, - "INSERT INTO session (id, username, expires_at, csrf_token) VALUES ($1, $2, $3, $4)", + ` + ---- Create session + INSERT INTO session (id, username, expires_at, csrf_token) VALUES ($1, $2, $3, $4) + `, session.ID, session.Username, session.ExpiresAt, session.CSRFToken, ) if err != nil { diff --git a/src/db/db.go b/src/db/db.go index 5f1a42f4..b97b91bf 100644 --- a/src/db/db.go +++ b/src/db/db.go @@ -12,38 +12,11 @@ import ( "git.handmade.network/hmn/hmn/src/config" "git.handmade.network/hmn/hmn/src/logging" "git.handmade.network/hmn/hmn/src/oops" - "git.handmade.network/hmn/hmn/src/utils" "github.com/google/uuid" - zerologadapter "github.com/jackc/pgx-zerolog" "github.com/jackc/pgx/v5" - "github.com/jackc/pgx/v5/pgconn" "github.com/jackc/pgx/v5/pgtype" - "github.com/jackc/pgx/v5/pgxpool" - "github.com/jackc/pgx/v5/tracelog" - "github.com/rs/zerolog/log" ) -/* -A general error to be used when no results are found. This is the error returned -by QueryOne, and can generally be used by other database helpers that fetch a single -result but find nothing. -*/ -var NotFound = errors.New("not found") - -// This interface should match both a direct pgx connection or a pgx transaction. -type ConnOrTx interface { - Query(ctx context.Context, sql string, args ...any) (pgx.Rows, error) - QueryRow(ctx context.Context, sql string, args ...any) pgx.Row - Exec(ctx context.Context, sql string, args ...any) (pgconn.CommandTag, error) - CopyFrom(ctx context.Context, tableName pgx.Identifier, columnNames []string, rowSrc pgx.CopyFromSource) (int64, error) - - // Both raw database connections and transactions in pgx can begin/commit - // transactions. For database connections it does the obvious thing; for - // transactions it creates a "pseudo-nested transaction" but conceptually - // works the same. See the documentation of pgx.Tx.Begin. - Begin(ctx context.Context) (pgx.Tx, error) -} - var pgTypeMap = pgtype.NewMap() func init() { @@ -51,68 +24,12 @@ func init() { pgTypeMap.TypeForValue(nil) } -// Creates a new connection to the HMN database. -// This connection is not safe for concurrent use. -func NewConn() *pgx.Conn { - return NewConnWithConfig(config.PostgresConfig{}) -} - -func NewConnWithConfig(cfg config.PostgresConfig) *pgx.Conn { - cfg = overrideDefaultConfig(cfg) - - pgcfg, err := pgx.ParseConfig(cfg.DSN()) - - pgcfg.Tracer = &tracelog.TraceLog{ - Logger: zerologadapter.NewLogger(log.Logger), - LogLevel: cfg.LogLevel, - } - - conn, err := pgx.ConnectConfig(context.Background(), pgcfg) - if err != nil { - panic(oops.New(err, "failed to connect to database")) - } - - return conn -} - -// Creates a connection pool for the HMN database. -// The resulting pool is safe for concurrent use. -func NewConnPool() *pgxpool.Pool { - return NewConnPoolWithConfig(config.PostgresConfig{}) -} - -func NewConnPoolWithConfig(cfg config.PostgresConfig) *pgxpool.Pool { - cfg = overrideDefaultConfig(cfg) - - pgcfg, err := pgxpool.ParseConfig(cfg.DSN()) - - pgcfg.MinConns = cfg.MinConn - pgcfg.MaxConns = cfg.MaxConn - pgcfg.ConnConfig.Tracer = &tracelog.TraceLog{ - Logger: zerologadapter.NewLogger(log.Logger), - LogLevel: cfg.LogLevel, - } - - conn, err := pgxpool.NewWithConfig(context.Background(), pgcfg) - if err != nil { - panic(oops.New(err, "failed to create database connection pool")) - } - - return conn -} - -func overrideDefaultConfig(cfg config.PostgresConfig) config.PostgresConfig { - return config.PostgresConfig{ - User: utils.OrDefault(cfg.User, config.Config.Postgres.User), - Password: utils.OrDefault(cfg.Password, config.Config.Postgres.Password), - Hostname: utils.OrDefault(cfg.Hostname, config.Config.Postgres.Hostname), - Port: utils.OrDefault(cfg.Port, config.Config.Postgres.Port), - DbName: utils.OrDefault(cfg.DbName, config.Config.Postgres.DbName), - LogLevel: utils.OrDefault(cfg.LogLevel, config.Config.Postgres.LogLevel), - MinConn: utils.OrDefault(cfg.MinConn, config.Config.Postgres.MinConn), - MaxConn: utils.OrDefault(cfg.MaxConn, config.Config.Postgres.MaxConn), - } -} +/* +A general error to be used when no results are found. This is the error returned +by QueryOne, and can generally be used by other database helpers that fetch a single +result but find nothing. +*/ +var NotFound = errors.New("not found") /* Performs a SQL query and returns a slice of all the result rows. The query is just plain SQL, but make sure to read the package documentation for details. You must explicitly provide the type argument - this is how it knows what Go type to map the results to, and it cannot be inferred. diff --git a/src/db/query_builder.go b/src/db/query_builder.go index d8dcb41d..b9ccd33e 100644 --- a/src/db/query_builder.go +++ b/src/db/query_builder.go @@ -33,6 +33,10 @@ func (qb *QueryBuilder) Add(sql string, args ...any) { qb.sql.WriteString("\n") } +func (qb *QueryBuilder) AddName(name string) { + qb.Add("---- " + name + "\n") +} + func (qb *QueryBuilder) String() string { return qb.sql.String() } diff --git a/src/email/email.go b/src/email/email.go index 7d1ba631..192b1922 100644 --- a/src/email/email.go +++ b/src/email/email.go @@ -34,9 +34,10 @@ func SendRegistrationEmail( destination string, perf *perf.RequestPerf, ) error { - perf.StartBlock("EMAIL", "Registration email") + defer perf.StartBlock("EMAIL", "Registration email").End() - perf.StartBlock("EMAIL", "Rendering template") + b1 := perf.StartBlock("EMAIL", "Rendering template") + defer b1.End() contents, err := renderTemplate("email_registration.html", RegistrationEmailData{ Name: toName, HomepageUrl: hmnurl.BuildHomepage(), @@ -45,16 +46,15 @@ func SendRegistrationEmail( if err != nil { return err } - perf.EndBlock() + b1.End() - perf.StartBlock("EMAIL", "Sending email") + b2 := perf.StartBlock("EMAIL", "Sending email") + defer b2.End() err = sendMail(toAddress, toName, "[Handmade Network] Registration confirmation", contents) if err != nil { return oops.New(err, "Failed to send email") } - perf.EndBlock() - - perf.EndBlock() + b2.End() return nil } @@ -73,9 +73,10 @@ func SendExistingAccountEmail( destination string, perf *perf.RequestPerf, ) error { - perf.StartBlock("EMAIL", "Existing account email") + defer perf.StartBlock("EMAIL", "Existing account email").End() - perf.StartBlock("EMAIL", "Rendering template") + b1 := perf.StartBlock("EMAIL", "Rendering template") + defer b1.End() contents, err := renderTemplate("email_account_existing.html", ExistingAccountEmailData{ Name: toName, Username: username, @@ -85,16 +86,15 @@ func SendExistingAccountEmail( if err != nil { return err } - perf.EndBlock() + b1.End() - perf.StartBlock("EMAIL", "Sending email") + b2 := perf.StartBlock("EMAIL", "Sending email") + defer b2.End() err = sendMail(toAddress, toName, "[Handmade Network] You already have an account!", contents) if err != nil { return oops.New(err, "Failed to send email") } - perf.EndBlock() - - perf.EndBlock() + b2.End() return nil } @@ -106,9 +106,10 @@ type PasswordResetEmailData struct { } func SendPasswordReset(toAddress string, toName string, username string, resetToken string, expiration time.Time, perf *perf.RequestPerf) error { - perf.StartBlock("EMAIL", "Password reset email") + defer perf.StartBlock("EMAIL", "Password reset email").End() - perf.StartBlock("EMAIL", "Rendering template") + b1 := perf.StartBlock("EMAIL", "Rendering template") + defer b1.End() contents, err := renderTemplate("email_password_reset.html", PasswordResetEmailData{ Name: toName, DoPasswordResetUrl: hmnurl.BuildDoPasswordReset(username, resetToken), @@ -117,16 +118,15 @@ func SendPasswordReset(toAddress string, toName string, username string, resetTo if err != nil { return err } - perf.EndBlock() + b1.End() - perf.StartBlock("EMAIL", "Sending email") + b2 := perf.StartBlock("EMAIL", "Sending email") + defer b2.End() err = sendMail(toAddress, toName, "[Handmade Network] Your password reset request", contents) if err != nil { return oops.New(err, "Failed to send email") } - perf.EndBlock() - - perf.EndBlock() + b2.End() return nil } @@ -142,8 +142,7 @@ type TimeMachineEmailData struct { } func SendTimeMachineEmail(profileUrl, username, userEmail, discordUsername string, mediaUrls []string, deviceInfo, description string, perf *perf.RequestPerf) error { - perf.StartBlock("EMAIL", "Time machine email") - defer perf.EndBlock() + defer perf.StartBlock("EMAIL", "Time machine email").End() contents, err := renderTemplate("email_time_machine.html", TimeMachineEmailData{ ProfileUrl: profileUrl, diff --git a/src/hmndata/jams.go b/src/hmndata/jams.go index 8f5d2e3f..9e4dca2f 100644 --- a/src/hmndata/jams.go +++ b/src/hmndata/jams.go @@ -201,6 +201,7 @@ func JamBySlug(slug string) Jam { func FetchJamsForProject(ctx context.Context, dbConn db.ConnOrTx, user *models.User, projectId int) ([]*models.JamProject, error) { jamProjects, err := db.Query[models.JamProject](ctx, dbConn, ` + ---- Fetch jams for project SELECT $columns FROM jam_project WHERE project_id = $1 diff --git a/src/hmndata/project_helper.go b/src/hmndata/project_helper.go index 959a794a..71322a0d 100644 --- a/src/hmndata/project_helper.go +++ b/src/hmndata/project_helper.go @@ -60,9 +60,7 @@ func FetchProjects( currentUser *models.User, q ProjectsQuery, ) ([]ProjectAndStuff, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch projects") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "PROJECT", "Fetch projects").End() tx, err := dbConn.Begin(ctx) if err != nil { @@ -80,6 +78,7 @@ func FetchProjects( // Fetch all valid projects (not yet subject to user permission checks) var qb db.QueryBuilder + qb.AddName("Fetch projects") if len(q.OrderBy) > 0 { qb.Add(`SELECT * FROM (`) } @@ -174,6 +173,7 @@ func FetchProjects( return nil, err } + b := perf.StartBlock(ctx, "PROJECT", "Compute permissions") var res []ProjectAndStuff for i, p := range projectRows { owners := projectOwners[i].Owners @@ -232,6 +232,7 @@ func FetchProjects( }) } } + b.End() err = tx.Commit(ctx) if err != nil { @@ -253,6 +254,8 @@ func FetchProject( projectID int, q ProjectsQuery, ) (ProjectAndStuff, error) { + defer perf.StartBlock(ctx, "PROJECT", "Fetch project").End() + q.ProjectIDs = []int{projectID} q.Limit = 1 q.Offset = 0 @@ -281,6 +284,8 @@ func FetchProjectBySlug( projectSlug string, q ProjectsQuery, ) (ProjectAndStuff, error) { + defer perf.StartBlock(ctx, "PROJECT", "Fetch project by slug").End() + q.Slugs = []string{projectSlug} q.Limit = 1 q.Offset = 0 @@ -303,9 +308,7 @@ func CountProjects( currentUser *models.User, q ProjectsQuery, ) (int, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Count projects") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "PROJECT", "Count projects").End() q.Limit = 0 q.Offset = 0 @@ -338,9 +341,7 @@ func FetchMultipleProjectsOwners( dbConn db.ConnOrTx, projectIds []int, ) ([]ProjectOwners, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch owners for multiple projects") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "PROJECT", "Fetch owners for multiple projects").End() tx, err := dbConn.Begin(ctx) if err != nil { @@ -355,6 +356,7 @@ func FetchMultipleProjectsOwners( } userProjects, err := db.Query[userProject](ctx, tx, ` + ---- Fetch user/project pairs SELECT $columns FROM user_project WHERE project_id = ANY($1) @@ -430,9 +432,7 @@ func FetchProjectOwners( dbConn db.ConnOrTx, projectId int, ) ([]*models.User, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch owners for project") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "PROJECT", "Fetch project owners").End() projectOwners, err := FetchMultipleProjectsOwners(ctx, dbConn, []int{projectId}) if err != nil { @@ -458,6 +458,8 @@ func SetProjectTag( projectID int, tagText string, ) (*models.Tag, error) { + defer perf.StartBlock(ctx, "PROJECT", "Set project tag").End() + tx, err := dbConn.Begin(ctx) if err != nil { return nil, oops.New(err, "failed to start transaction") @@ -480,6 +482,7 @@ func SetProjectTag( // Create a tag tag, err := db.QueryOne[models.Tag](ctx, tx, ` + ---- Create a new tag INSERT INTO tag (text) VALUES ($1) RETURNING $columns `, @@ -493,6 +496,7 @@ func SetProjectTag( // Attach it to the project _, err = tx.Exec(ctx, ` + ---- Associate tag with project UPDATE project SET tag = $1 WHERE id = $2 @@ -506,6 +510,7 @@ func SetProjectTag( // Update the text of an existing one tag, err := db.QueryOne[models.Tag](ctx, tx, ` + ---- Update the text of the existing tag UPDATE tag SET text = $1 WHERE id = (SELECT tag FROM project WHERE id = $2) @@ -530,6 +535,7 @@ func SetProjectTag( func UpdateSnippetLastPostedForAllProjects(ctx context.Context, dbConn db.ConnOrTx) error { _, err := dbConn.Exec(ctx, ` + ---- Update snippet_last_posted for everything UPDATE project p SET (snippet_last_posted, all_last_updated) = ( SELECT COALESCE(MAX(s."when"), 'epoch'), diff --git a/src/hmndata/snippet_helper.go b/src/hmndata/snippet_helper.go index 73397f4c..6588b403 100644 --- a/src/hmndata/snippet_helper.go +++ b/src/hmndata/snippet_helper.go @@ -36,9 +36,7 @@ func FetchSnippets( currentUser *models.User, q SnippetQuery, ) ([]SnippetAndStuff, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch snippets") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "SNIPPET", "Fetch snippets").End() tx, err := dbConn.Begin(ctx) if err != nil { @@ -53,6 +51,7 @@ func FetchSnippets( // Get snippet IDs with this tag, then use that in the main query snippetIDs, err := db.QueryScalar[int](ctx, tx, ` + ---- Get snippet IDs for tag SELECT DISTINCT snippet_id FROM snippet_tag @@ -74,6 +73,7 @@ func FetchSnippets( // Get snippet IDs for these projects, then use that in the main query snippetIDs, err := db.QueryScalar[int](ctx, tx, ` + ---- Get snippet IDs for projects SELECT DISTINCT snippet_id FROM snippet_project @@ -92,6 +92,7 @@ func FetchSnippets( var qb db.QueryBuilder qb.Add( ` + ---- Get snippets SELECT $columns FROM snippet @@ -183,6 +184,7 @@ func FetchSnippets( } snippetTags, err := db.Query[snippetTagRow](ctx, tx, ` + ---- Get tags for snippets SELECT $columns FROM snippet_tag @@ -213,6 +215,7 @@ func FetchSnippets( } snippetProjects, err := db.Query[snippetProjectRow](ctx, tx, ` + ---- Get projects for snippets SELECT $columns FROM snippet_project WHERE snippet_id = ANY($1) @@ -257,6 +260,8 @@ func FetchSnippet( snippetID int, q SnippetQuery, ) (SnippetAndStuff, error) { + defer perf.StartBlock(ctx, "SNIPPET", "Fetch snippet").End() + q.IDs = []int{snippetID} q.Limit = 1 q.Offset = 0 @@ -280,6 +285,8 @@ func FetchSnippetForDiscordMessage( discordMessageID string, q SnippetQuery, ) (SnippetAndStuff, error) { + defer perf.StartBlock(ctx, "SNIPPET", "Fetch snippet for Discord message").End() + q.DiscordMessageIDs = []string{discordMessageID} q.Limit = 1 q.Offset = 0 diff --git a/src/hmndata/tag_helper.go b/src/hmndata/tag_helper.go index 94c3f556..3e9abbd2 100644 --- a/src/hmndata/tag_helper.go +++ b/src/hmndata/tag_helper.go @@ -17,13 +17,12 @@ type TagQuery struct { } func FetchTags(ctx context.Context, dbConn db.ConnOrTx, q TagQuery) ([]*models.Tag, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch tags") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "TAG", "Fetch tags").End() var qb db.QueryBuilder qb.Add( ` + ---- Fetch tags SELECT $columns FROM tag WHERE diff --git a/src/hmndata/threads_and_posts_helper.go b/src/hmndata/threads_and_posts_helper.go index 58d91c8e..45a1b5cd 100644 --- a/src/hmndata/threads_and_posts_helper.go +++ b/src/hmndata/threads_and_posts_helper.go @@ -56,9 +56,7 @@ func FetchThreads( currentUser *models.User, q ThreadsQuery, ) ([]ThreadAndStuff, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch threads") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "POST", "Fetch threads").End() var qb db.QueryBuilder @@ -69,6 +67,7 @@ func FetchThreads( qb.Add( ` + ---- Fetch threads SELECT $columns FROM thread @@ -191,6 +190,8 @@ func FetchThread( threadID int, q ThreadsQuery, ) (ThreadAndStuff, error) { + defer perf.StartBlock(ctx, "POST", "Fetch thread").End() + q.ThreadIDs = []int{threadID} q.Limit = 1 q.Offset = 0 @@ -213,9 +214,7 @@ func CountThreads( currentUser *models.User, q ThreadsQuery, ) (int, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Count threads") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "POST", "Count threads").End() var qb db.QueryBuilder @@ -226,6 +225,7 @@ func CountThreads( qb.Add( ` + ---- Count threads SELECT COUNT(*) FROM thread @@ -316,9 +316,7 @@ func FetchPosts( currentUser *models.User, q PostsQuery, ) ([]PostAndStuff, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch posts") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "POST", "Fetch posts").End() var qb db.QueryBuilder @@ -338,6 +336,7 @@ func FetchPosts( qb.Add( ` + ---- Fetch posts SELECT $columns FROM post @@ -474,6 +473,8 @@ func FetchThreadPosts( threadID int, q PostsQuery, ) (models.Thread, []PostAndStuff, error) { + defer perf.StartBlock(ctx, "POST", "Fetch posts for thread").End() + q.ThreadIDs = []int{threadID} res, err := FetchPosts(ctx, dbConn, currentUser, q) @@ -503,6 +504,8 @@ func FetchThreadPost( threadID, postID int, q PostsQuery, ) (PostAndStuff, error) { + defer perf.StartBlock(ctx, "POST", "Fetch post for thread").End() + q.ThreadIDs = []int{threadID} q.PostIDs = []int{postID} q.Limit = 1 @@ -534,6 +537,8 @@ func FetchPost( postID int, q PostsQuery, ) (PostAndStuff, error) { + defer perf.StartBlock(ctx, "POST", "Fetch post").End() + q.PostIDs = []int{postID} q.Limit = 1 q.Offset = 0 @@ -556,9 +561,7 @@ func CountPosts( currentUser *models.User, q PostsQuery, ) (int, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Count posts") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "POST", "Count posts").End() var qb db.QueryBuilder @@ -569,6 +572,7 @@ func CountPosts( qb.Add( ` + ---- Count posts SELECT COUNT(*) FROM post @@ -632,6 +636,7 @@ func UserCanEditPost(ctx context.Context, connOrTx db.ConnOrTx, user models.User authorID, err := db.QueryOneScalar[*int](ctx, connOrTx, ` + ---- Check if user can edit post SELECT post.author_id FROM post @@ -662,9 +667,12 @@ func CreateNewPost( unparsedContent string, ipString string, ) (postId, versionId int) { + defer perf.StartBlock(ctx, "POST", "Create post").End() + // Create post err := tx.QueryRow(ctx, ` + ---- Create new post INSERT INTO post (postdate, thread_id, thread_type, current_id, author_id, project_id, reply_id, preview) VALUES ($1, $2, $3, $4, $5, $6, $7, $8) RETURNING id @@ -723,12 +731,15 @@ func DeletePost( tx pgx.Tx, threadId, postId int, ) (threadDeleted bool) { + defer perf.StartBlock(ctx, "POST", "Delete post").End() + type threadInfo struct { FirstPostID int `db:"first_id"` Deleted bool `db:"deleted"` } info, err := db.QueryOne[threadInfo](ctx, tx, ` + ---- Get thread SELECT $columns FROM thread @@ -749,6 +760,7 @@ func DeletePost( // Just delete the whole thread and all its posts. _, err = tx.Exec(ctx, ` + ---- Mark thread as deleted UPDATE thread SET deleted = TRUE WHERE id = $1 @@ -757,6 +769,7 @@ func DeletePost( ) _, err = tx.Exec(ctx, ` + ---- Mark thread's posts as deleted UPDATE post SET deleted = TRUE WHERE thread_id = $1 @@ -769,6 +782,7 @@ func DeletePost( _, err = tx.Exec(ctx, ` + ---- Delete post UPDATE post SET deleted = TRUE WHERE @@ -795,6 +809,8 @@ func DeletePost( const maxPostContentLength = 200000 func CreatePostVersion(ctx context.Context, tx pgx.Tx, postId int, unparsedContent string, ipString string, editReason string, editorId *int) (versionId int) { + defer perf.StartBlock(ctx, "POST", "Create post version").End() + if len(unparsedContent) > maxPostContentLength { logging.ExtractLogger(ctx).Warn(). Str("preview", unparsedContent[:400]). @@ -815,6 +831,7 @@ func CreatePostVersion(ctx context.Context, tx pgx.Tx, postId int, unparsedConte // Create post version err := tx.QueryRow(ctx, ` + ---- Create post version INSERT INTO post_version (post_id, text_raw, text_parsed, ip, date, edit_reason, editor_id) VALUES ($1, $2, $3, $4, $5, $6, $7) RETURNING id @@ -834,6 +851,7 @@ func CreatePostVersion(ctx context.Context, tx pgx.Tx, postId int, unparsedConte // Update post with version id and preview _, err = tx.Exec(ctx, ` + ---- Update post to new version UPDATE post SET current_id = $1, preview = $2 WHERE id = $3 @@ -900,8 +918,11 @@ Returns errThreadEmpty if the thread contains no visible posts any more. You should probably mark the thread as deleted in this case. */ func FixThreadPostIds(ctx context.Context, conn db.ConnOrTx, threadId int) error { + defer perf.StartBlock(ctx, "POST", "Fix thread post IDs").End() + posts, err := db.Query[models.Post](ctx, conn, ` + ---- Get posts in thread SELECT $columns FROM post WHERE @@ -930,6 +951,7 @@ func FixThreadPostIds(ctx context.Context, conn db.ConnOrTx, threadId int) error _, err = conn.Exec(ctx, ` + ---- Update thread first/last UPDATE thread SET first_id = $1, last_id = $2 WHERE id = $3 diff --git a/src/hmndata/timeline_helper.go b/src/hmndata/timeline_helper.go index 7e44b1a0..847c1917 100644 --- a/src/hmndata/timeline_helper.go +++ b/src/hmndata/timeline_helper.go @@ -37,11 +37,10 @@ func FetchTimeline( currentUser *models.User, q TimelineQuery, ) ([]*TimelineItemAndStuff, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch timeline") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "TIMELINE", "Fetch timeline").End() var qb db.QueryBuilder + qb.AddName("Fetch base timeline data") currentUserId := -1 if currentUser != nil { @@ -247,9 +246,7 @@ func FetchTimeline( qb.Add(`LIMIT $? OFFSET $?`, q.Limit, q.Offset) } - perf.StartBlock("SQL", "Query timeline") results, err := db.Query[TimelineItemAndStuff](ctx, dbConn, qb.String(), qb.Args()...) - perf.EndBlock() if err != nil { return nil, oops.New(err, "failed to fetch timeline items") } @@ -260,8 +257,6 @@ func FetchTimeline( } } - perf.StartBlock("TIMELINE", "Fixup projects") - defer perf.EndBlock() projectsSeen := make(map[int]bool) var projectIds []int var snippetIds []int @@ -286,16 +281,15 @@ func FetchTimeline( SnippetID int `db:"snippet_id"` ProjectID int `db:"project_id"` } - perf.StartBlock("SQL", "Fetch snippet projects") snippetProjects, err := db.Query[snippetProjectRow](ctx, dbConn, ` + ---- Fetch snippet projects SELECT $columns FROM snippet_project WHERE snippet_id = ANY($1) `, snippetIds, ) - perf.EndBlock() if err != nil { return nil, oops.New(err, "failed to fetch project ids for timeline") } diff --git a/src/hmndata/twitch.go b/src/hmndata/twitch.go index aa6f56b8..4a3e1249 100644 --- a/src/hmndata/twitch.go +++ b/src/hmndata/twitch.go @@ -28,12 +28,12 @@ type TwitchStreamersQuery struct { } func FetchTwitchStreamers(ctx context.Context, dbConn db.ConnOrTx, q TwitchStreamersQuery) ([]TwitchStreamer, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch twitch streamers") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "TWITCH", "Fetch Twitch streamers").End() + var qb db.QueryBuilder qb.Add( ` + ---- Fetch Twitch links SELECT $columns{link} FROM link @@ -108,8 +108,11 @@ func FetchTwitchStreamers(ctx context.Context, dbConn db.ConnOrTx, q TwitchStrea } func FetchTwitchLoginsForUserOrProject(ctx context.Context, dbConn db.ConnOrTx, userId *int, projectId *int) ([]string, error) { + defer perf.StartBlock(ctx, "TWITCH", "Fetch Twitch logins").End() + links, err := db.Query[models.Link](ctx, dbConn, ` + ---- Fetch Twitch links SELECT $columns FROM link diff --git a/src/hmndata/user_helper.go b/src/hmndata/user_helper.go index ccf098de..742ba964 100644 --- a/src/hmndata/user_helper.go +++ b/src/hmndata/user_helper.go @@ -31,9 +31,7 @@ func FetchUsers( currentUser *models.User, q UsersQuery, ) ([]*models.User, error) { - perf := perf.ExtractPerf(ctx) - perf.StartBlock("SQL", "Fetch users") - defer perf.EndBlock() + defer perf.StartBlock(ctx, "USER", "Fetch users").End() var currentUserID *int if currentUser != nil { @@ -52,6 +50,7 @@ func FetchUsers( var qb db.QueryBuilder qb.Add(` + ---- Fetch users SELECT $columns FROM hmn_user @@ -116,6 +115,8 @@ func FetchUser( userID int, q UsersQuery, ) (*models.User, error) { + defer perf.StartBlock(ctx, "USER", "Fetch user").End() + q.UserIDs = []int{userID} res, err := FetchUsers(ctx, dbConn, currentUser, q) @@ -144,6 +145,8 @@ func FetchUserByUsername( username string, q UsersQuery, ) (*models.User, error) { + defer perf.StartBlock(ctx, "USER", "Fetch user by username").End() + q.Usernames = []string{username} res, err := FetchUsers(ctx, dbConn, currentUser, q) diff --git a/src/models/subforum.go b/src/models/subforum.go index b9d04a75..419a965f 100644 --- a/src/models/subforum.go +++ b/src/models/subforum.go @@ -45,6 +45,7 @@ func (node *SubforumTreeNode) GetLineage() []*Subforum { func GetFullSubforumTree(ctx context.Context, conn db.ConnOrTx) SubforumTree { subforums, err := db.Query[Subforum](ctx, conn, ` + ---- Get subforum tree SELECT $columns FROM subforum ORDER BY sort, id ASC diff --git a/src/perf/perf.go b/src/perf/perf.go index d6965a92..2aca5473 100644 --- a/src/perf/perf.go +++ b/src/perf/perf.go @@ -32,8 +32,13 @@ func (rp *RequestPerf) EndRequest() { return } - for rp.EndBlock() { + // Close any open blocks (arguably a bug! do better, user!) + for i := len(rp.Blocks) - 1; i >= 0; i -= 1 { + if rp.Blocks[i].End.Equal(time.Time{}) { + rp.Blocks[i].End = time.Now() + } } + rp.End = time.Now() } @@ -52,11 +57,38 @@ func (rp *RequestPerf) Checkpoint(category, description string) { rp.Blocks = append(rp.Blocks, checkpoint) } -func (rp *RequestPerf) StartBlock(category, description string) { - if rp == nil { +type BlockHandle struct { + rp *RequestPerf + ended bool +} + +func (b *BlockHandle) End() { + if b.rp == nil { + return + } + if b.ended { return } + b.ended = true + for i := len(b.rp.Blocks) - 1; i >= 0; i -= 1 { + if b.rp.Blocks[i].End.Equal(time.Time{}) { + b.rp.Blocks[i].End = time.Now() + return + } + } +} + +func StartBlock(ctx context.Context, category, description string) *BlockHandle { + p := ExtractPerf(ctx) + return p.StartBlock(category, description) +} + +func (rp *RequestPerf) StartBlock(category, description string) *BlockHandle { + if rp == nil { + return &BlockHandle{} + } + now := time.Now() checkpoint := PerfBlock{ Start: now, @@ -65,22 +97,25 @@ func (rp *RequestPerf) StartBlock(category, description string) { Description: description, } rp.Blocks = append(rp.Blocks, checkpoint) -} - -func (rp *RequestPerf) EndBlock() bool { - if rp == nil { - return false - } - for i := len(rp.Blocks) - 1; i >= 0; i -= 1 { - if rp.Blocks[i].End.Equal(time.Time{}) { - rp.Blocks[i].End = time.Now() - return true - } + return &BlockHandle{ + rp: rp, } - return false } +// func (rp *RequestPerf) EndLatestBlock() { +// if rp == nil { +// return +// } + +// for i := len(rp.Blocks) - 1; i >= 0; i -= 1 { +// if rp.Blocks[i].End.Equal(time.Time{}) { +// rp.Blocks[i].End = time.Now() +// break +// } +// } +// } + func (rp *RequestPerf) MsFromStart(block *PerfBlock) float64 { if rp == nil { return 0 diff --git a/src/twitch/rest.go b/src/twitch/rest.go index 0207783d..b2efb83a 100644 --- a/src/twitch/rest.go +++ b/src/twitch/rest.go @@ -17,6 +17,7 @@ import ( "git.handmade.network/hmn/hmn/src/hmnurl" "git.handmade.network/hmn/hmn/src/logging" "git.handmade.network/hmn/hmn/src/oops" + "git.handmade.network/hmn/hmn/src/perf" "git.handmade.network/hmn/hmn/src/utils" ) @@ -39,6 +40,8 @@ type twitchUser struct { } func getTwitchUsersByLogin(ctx context.Context, logins []string) ([]twitchUser, error) { + defer perf.StartBlock(ctx, "TwitchAPI", "Fetch twitch user info").End() + result := make([]twitchUser, 0, len(logins)) numChunks := len(logins)/100 + 1 for i := 0; i < numChunks; i++ { @@ -89,6 +92,8 @@ func getTwitchUsersByLogin(ctx context.Context, logins []string) ([]twitchUser, } func getStreamStatus(ctx context.Context, twitchIDs []string) ([]streamStatus, error) { + defer perf.StartBlock(ctx, "TwitchAPI", "Fetch stream status").End() + result := make([]streamStatus, 0, len(twitchIDs)) numChunks := len(twitchIDs)/100 + 1 for i := 0; i < numChunks; i++ { @@ -191,6 +196,8 @@ func getArchivedVideos(ctx context.Context, videoIDs []string) ([]archivedVideo, } func getArchivedVideosByQuery(ctx context.Context, query url.Values) ([]archivedVideo, error) { + defer perf.StartBlock(ctx, "TwitchAPI", "Query archived videos").End() + req, err := http.NewRequestWithContext(ctx, "GET", buildUrl("/videos", query.Encode()), nil) if err != nil { return nil, oops.New(err, "failed to create request") @@ -275,6 +282,8 @@ type twitchEventSub struct { } func getEventSubscriptions(ctx context.Context) ([]twitchEventSub, error) { + defer perf.StartBlock(ctx, "TwitchAPI", "Fetch event subscriptions").End() + result := make([]twitchEventSub, 0) after := "" for { @@ -337,6 +346,8 @@ func getEventSubscriptions(ctx context.Context) ([]twitchEventSub, error) { } func subscribeToEvent(ctx context.Context, eventType string, twitchID string) error { + defer perf.StartBlock(ctx, "TwitchAPI", fmt.Sprintf("Subscribe to event: %s", eventType)).End() + type eventBody struct { Type string `json:"type"` Version string `json:"version"` @@ -388,6 +399,8 @@ func subscribeToEvent(ctx context.Context, eventType string, twitchID string) er } func unsubscribeFromEvent(ctx context.Context, eventID string) error { + defer perf.StartBlock(ctx, "TwitchAPI", "Unsubscribe from event").End() + query := url.Values{} query.Add("id", eventID) req, err := http.NewRequestWithContext(ctx, "DELETE", buildUrl("/eventsub/subscriptions", query.Encode()), nil) @@ -415,6 +428,8 @@ func unsubscribeFromEvent(ctx context.Context, eventID string) error { var twitchNotFound = errors.New("Twitch API 404") func doRequest(ctx context.Context, waitOnRateLimit bool, req *http.Request) (*http.Response, error) { + defer perf.StartBlock(ctx, "TwitchAPI", "API Request").End() + serviceUnavailable := false numRetries := 5 @@ -508,6 +523,8 @@ type AccessTokenResponse struct { } func refreshAccessToken(ctx context.Context) error { + defer perf.StartBlock(ctx, "TwitchAPI", "Refresh access token").End() + logging.ExtractLogger(ctx).Info().Msg("Refreshing twitch token") query := url.Values{} query.Add("client_id", config.Config.Twitch.ClientID) diff --git a/src/twitch/twitch.go b/src/twitch/twitch.go index 495ad001..cda96166 100644 --- a/src/twitch/twitch.go +++ b/src/twitch/twitch.go @@ -252,13 +252,11 @@ func syncWithTwitch(ctx context.Context, dbConn *pgxpool.Pool, updateAll bool, u } var stats twitchSyncStats - p.StartBlock("SQL", "Fetch list of streamers") streamers, err := hmndata.FetchTwitchStreamers(ctx, dbConn, hmndata.TwitchStreamersQuery{}) if err != nil { log.Error().Err(err).Msg("Error while monitoring twitch") return } - p.EndBlock() needID := make([]string, 0) streamerMap := make(map[string]*hmndata.TwitchStreamer) @@ -269,14 +267,12 @@ func syncWithTwitch(ctx context.Context, dbConn *pgxpool.Pool, updateAll bool, u twitchUsers := []twitchUser{} if len(needID) > 0 { - p.StartBlock("TwitchAPI", "Fetch twitch user info") log.Debug().Interface("needID", needID).Msg("IDs") twitchUsers, err = getTwitchUsersByLogin(ctx, needID) if err != nil { log.Error().Err(err).Msg("Error while monitoring twitch") return } - p.EndBlock() } for _, tu := range twitchUsers { @@ -290,13 +286,11 @@ func syncWithTwitch(ctx context.Context, dbConn *pgxpool.Pool, updateAll bool, u } } - p.StartBlock("TwitchAPI", "Fetch event subscriptions") subscriptions, err := getEventSubscriptions(ctx) if err != nil { log.Error().Err(err).Msg("Error while monitoring twitch") return } - p.EndBlock() type isSubbedByType map[string]bool @@ -336,7 +330,9 @@ func syncWithTwitch(ctx context.Context, dbConn *pgxpool.Pool, updateAll bool, u } if config.Config.Env != config.Dev { // NOTE(asaf): Can't subscribe to events from dev. We need a non-localhost callback url. - p.StartBlock("TwitchAPI", "Sync subscriptions with twitch") + b := p.StartBlock("TwitchAPI", "Sync subscriptions with twitch") + defer b.End() + for _, ev := range toUnsub { err = unsubscribeFromEvent(ctx, ev.EventID) if err != nil { @@ -358,7 +354,8 @@ func syncWithTwitch(ctx context.Context, dbConn *pgxpool.Pool, updateAll bool, u } } } - p.EndBlock() + + b.End() } tx, err := dbConn.Begin(ctx) @@ -371,16 +368,17 @@ func syncWithTwitch(ctx context.Context, dbConn *pgxpool.Pool, updateAll bool, u for _, streamer := range validStreamers { allIDs = append(allIDs, streamer.TwitchID) } - p.StartBlock("SQL", "Remove untracked streamers") _, err = tx.Exec(ctx, - `DELETE FROM twitch_latest_status WHERE NOT (twitch_id = ANY($1))`, + ` + ---- Remove untracked streamers + DELETE FROM twitch_latest_status WHERE NOT (twitch_id = ANY($1)) + `, allIDs, ) if err != nil { log.Error().Err(err).Msg("Failed to remove untracked twitch ids from streamer list in db") return } - p.EndBlock() usersToUpdate := make([]string, 0) if updateAll { @@ -399,43 +397,47 @@ func syncWithTwitch(ctx context.Context, dbConn *pgxpool.Pool, updateAll bool, u } if len(usersToUpdate) > 0 { - p.StartBlock("TwitchAPI", "Fetch twitch stream statuses") statuses, err := getStreamStatus(ctx, usersToUpdate) if err != nil { log.Error().Err(err).Msg("failed to fetch stream statuses") return } twitchLog(ctx, tx, models.TwitchLogTypeOther, "", "Batch resync", fmt.Sprintf("%#v", statuses)) - p.EndBlock() - p.StartBlock("SQL", "Update stream statuses in db") - for _, twitchId := range usersToUpdate { - var status *streamStatus - for idx, st := range statuses { - if st.TwitchID == twitchId { - status = &statuses[idx] - break - } - } - if status == nil { - twitchLogin := "" - for _, streamer := range validStreamers { - if streamer.TwitchID == twitchId { - twitchLogin = streamer.TwitchLogin + + { + b := p.StartBlock("SQL", "Update stream statuses in db") + defer b.End() + + for _, twitchId := range usersToUpdate { + var status *streamStatus + for idx, st := range statuses { + if st.TwitchID == twitchId { + status = &statuses[idx] break } } - status = &streamStatus{ - TwitchID: twitchId, - TwitchLogin: twitchLogin, + if status == nil { + twitchLogin := "" + for _, streamer := range validStreamers { + if streamer.TwitchID == twitchId { + twitchLogin = streamer.TwitchLogin + break + } + } + status = &streamStatus{ + TwitchID: twitchId, + TwitchLogin: twitchLogin, + } + } + twitchLog(ctx, tx, models.TwitchLogTypeREST, status.TwitchLogin, "Resync", fmt.Sprintf("%#v", status)) + err = gotRESTUpdate(ctx, tx, status) + if err != nil { + log.Error().Err(err).Msg("failed to update twitch stream status") } } - twitchLog(ctx, tx, models.TwitchLogTypeREST, status.TwitchLogin, "Resync", fmt.Sprintf("%#v", status)) - err = gotRESTUpdate(ctx, tx, status) - if err != nil { - log.Error().Err(err).Msg("failed to update twitch stream status") - } + + b.End() } - p.EndBlock() } err = tx.Commit(ctx) if err != nil { diff --git a/src/website/admin.go b/src/website/admin.go index 47d134ad..4777755e 100644 --- a/src/website/admin.go +++ b/src/website/admin.go @@ -69,10 +69,8 @@ func AdminAtomFeed(c *RequestContext) ResponseData { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch unapproved posts")) } - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() for _, post := range unapprovedPosts { postItem := MakePostListItem( @@ -133,10 +131,8 @@ type unapprovedUserData struct { } func AdminApprovalQueue(c *RequestContext) ResponseData { - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() potentialUsers, err := db.QueryScalar[int](c, c.Conn, ` diff --git a/src/website/auth.go b/src/website/auth.go index 39a7330e..8bd1050b 100644 --- a/src/website/auth.go +++ b/src/website/auth.go @@ -90,6 +90,7 @@ func Login(c *RequestContext) ResponseData { user, err := db.QueryOne[models.User](c, c.Conn, ` + ---- Get user SELECT $columns FROM hmn_user WHERE LOWER(username) = LOWER($1) @@ -134,6 +135,7 @@ func LoginWithDiscord(c *RequestContext) ResponseData { pendingLogin, err := db.QueryOne[models.PendingLogin](c, c.Conn, ` + ---- Create pending login INSERT INTO pending_login (id, expires_at, destination_url) VALUES ($1, $2, $3) RETURNING $columns @@ -215,56 +217,69 @@ func RegisterNewUserSubmit(c *RequestContext) ResponseData { return c.RejectRequest("Password too short") } - c.Perf.StartBlock("SQL", "Check blacklist") - blacklisted, err := blacklist(c, c.Conn, username, emailAddress) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to check email blacklist")) - } - if blacklisted { - // NOTE(asaf): Silent rejection so we don't allow attackers to harvest emails. - logEvent.Msg("blacklisted registration attempt") - return c.Redirect(hmnurl.BuildRegistrationSuccess(), http.StatusSeeOther) + { + b := c.Perf.StartBlock("SQL", "Check blacklist") + defer b.End() + + blacklisted, err := isBlacklisted(c, c.Conn, username, emailAddress) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to check email blacklist")) + } + if blacklisted { + // NOTE(asaf): Silent rejection so we don't allow attackers to harvest emails. + logEvent.Msg("blacklisted registration attempt") + return c.Redirect(hmnurl.BuildRegistrationSuccess(), http.StatusSeeOther) + } + + b.End() } - c.Perf.EndBlock() - c.Perf.StartBlock("SQL", "Check for existing usernames and emails") + var existingUser *models.User userAlreadyExists := true - _, err = db.QueryOneScalar[int](c, c.Conn, - ` - SELECT id - FROM hmn_user - WHERE LOWER(username) = LOWER($1) - `, - username, - ) - if err != nil { + { + b := c.Perf.StartBlock("AUTH", "Check for existing usernames and emails") + defer b.End() + + _, err := db.QueryOneScalar[int](c, c.Conn, + ` + ---- Load users with same username + SELECT id + FROM hmn_user + WHERE LOWER(username) = LOWER($1) + `, + username, + ) + if err != nil { + if errors.Is(err, db.NotFound) { + userAlreadyExists = false + } else { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch user")) + } + } + + if userAlreadyExists { + logEvent.Msg("registration attempt with duplicate username") + return c.RejectRequest(fmt.Sprintf("Username (%s) already exists.", username)) + } + + existingUser, err = db.QueryOne[models.User](c, c.Conn, + ` + ---- Load users with same email + SELECT $columns + FROM hmn_user + WHERE LOWER(email) = LOWER($1) + `, + emailAddress, + ) if errors.Is(err, db.NotFound) { - userAlreadyExists = false - } else { + // this is fine + } else if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch user")) } - } - if userAlreadyExists { - logEvent.Msg("registration attempt with duplicate username") - return c.RejectRequest(fmt.Sprintf("Username (%s) already exists.", username)) + b.End() } - existingUser, err := db.QueryOne[models.User](c, c.Conn, - ` - SELECT $columns - FROM hmn_user - WHERE LOWER(email) = LOWER($1) - `, - emailAddress, - ) - if errors.Is(err, db.NotFound) { - // this is fine - } else if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch user")) - } - c.Perf.EndBlock() - if existingUser != nil { // Render the page as if it was a successful new registration, but // instead send an email to the duplicate email address containing @@ -288,7 +303,6 @@ func RegisterNewUserSubmit(c *RequestContext) ResponseData { hashed := auth.HashPassword(password) - c.Perf.StartBlock("SQL", "Create user and one time token") tx, err := c.Conn.Begin(c) if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to start db transaction")) @@ -297,35 +311,44 @@ func RegisterNewUserSubmit(c *RequestContext) ResponseData { now := time.Now() - var newUserId int - err = tx.QueryRow(c, - ` - INSERT INTO hmn_user (username, email, password, date_joined, name, registration_ip) - VALUES ($1, $2, $3, $4, $5, $6) - RETURNING id - `, - username, emailAddress, hashed.String(), now, displayName, c.GetIP(), - ).Scan(&newUserId) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to store user")) - } + var ott string + { + b := c.Perf.StartBlock("AUTH", "Create user and one time token") + defer b.End() - ott := models.GenerateToken() - _, err = tx.Exec(c, - ` - INSERT INTO one_time_token (token_type, created, expires, token_content, owner_id) - VALUES($1, $2, $3, $4, $5) - `, - models.TokenTypeRegistration, - now, - now.Add(time.Hour*24*7), - ott, - newUserId, - ) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to store one-time token")) + var newUserId int + err = tx.QueryRow(c, + ` + ---- Create new user + INSERT INTO hmn_user (username, email, password, date_joined, name, registration_ip) + VALUES ($1, $2, $3, $4, $5, $6) + RETURNING id + `, + username, emailAddress, hashed.String(), now, displayName, c.GetIP(), + ).Scan(&newUserId) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to store user")) + } + + ott = models.GenerateToken() + _, err = tx.Exec(c, + ` + ---- Create OTT + INSERT INTO one_time_token (token_type, created, expires, token_content, owner_id) + VALUES($1, $2, $3, $4, $5) + `, + models.TokenTypeRegistration, + now, + now.Add(time.Hour*24*7), + ott, + newUserId, + ) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to store one-time token")) + } + + b.End() } - c.Perf.EndBlock() mailName := displayName if mailName == "" { @@ -348,12 +371,10 @@ func RegisterNewUserSubmit(c *RequestContext) ResponseData { logging.Debug().Str("Confirmation url", confirmUrl).Msg("New user requires email confirmation") } - c.Perf.StartBlock("SQL", "Commit user") err = tx.Commit(c) if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to commit user to the db")) } - c.Perf.EndBlock() logEvent.Msg("registration succeeded") return c.Redirect(hmnurl.BuildRegistrationSuccess(), http.StatusSeeOther) @@ -457,41 +478,48 @@ func EmailConfirmationSubmit(c *RequestContext) ResponseData { return res } - c.Perf.StartBlock("SQL", "Updating user status and deleting token") tx, err := c.Conn.Begin(c) if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to start db transaction")) } defer tx.Rollback(c) - _, err = tx.Exec(c, - ` - UPDATE hmn_user - SET status = $1 - WHERE id = $2 - `, - models.UserStatusConfirmed, - validationResult.User.ID, - ) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to update user status")) - } + { + b := c.Perf.StartBlock("SQL", "Updating user status and deleting token") + defer b.End() - _, err = tx.Exec(c, - ` - DELETE FROM one_time_token WHERE id = $1 - `, - validationResult.OneTimeToken.ID, - ) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to delete one time token")) - } + _, err = tx.Exec(c, + ` + ---- Confirm user via email + UPDATE hmn_user + SET status = $1 + WHERE id = $2 + `, + models.UserStatusConfirmed, + validationResult.User.ID, + ) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to update user status")) + } - err = tx.Commit(c) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to commit transaction")) + _, err = tx.Exec(c, + ` + ---- Delete OTT + DELETE FROM one_time_token WHERE id = $1 + `, + validationResult.OneTimeToken.ID, + ) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to delete one time token")) + } + + err = tx.Commit(c) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to commit transaction")) + } + + b.End() } - c.Perf.EndBlock() redirect := hmnurl.BuildHomepage() if destination != "" && urlIsLocal(destination) { @@ -547,12 +575,12 @@ func RequestPasswordResetSubmit(c *RequestContext) ResponseData { return c.RejectRequest("You must provide a username and an email address.") } - c.Perf.StartBlock("SQL", "Fetching user") type userQuery struct { User models.User `db:"hmn_user"` } user, err := db.QueryOne[models.User](c, c.Conn, ` + ---- Get user for password reset SELECT $columns FROM hmn_user WHERE @@ -562,7 +590,6 @@ func RequestPasswordResetSubmit(c *RequestContext) ResponseData { username, emailAddress, ) - c.Perf.EndBlock() if err != nil { if !errors.Is(err, db.NotFound) { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to look up user by username")) @@ -570,9 +597,9 @@ func RequestPasswordResetSubmit(c *RequestContext) ResponseData { } if user != nil && user.Status != models.UserStatusBanned { - c.Perf.StartBlock("SQL", "Fetching existing token") resetToken, err := db.QueryOne[models.OneTimeToken](c, c.Conn, ` + ---- Fetching existing token SELECT $columns FROM one_time_token WHERE @@ -582,7 +609,6 @@ func RequestPasswordResetSubmit(c *RequestContext) ResponseData { models.TokenTypePasswordReset, user.ID, ) - c.Perf.EndBlock() if err != nil { if !errors.Is(err, db.NotFound) { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch onetimetoken for user")) @@ -592,15 +618,14 @@ func RequestPasswordResetSubmit(c *RequestContext) ResponseData { if resetToken != nil { if resetToken.Expires.Before(now.Add(time.Minute * 30)) { // NOTE(asaf): Expired or about to expire - c.Perf.StartBlock("SQL", "Deleting expired token") _, err = c.Conn.Exec(c, ` + ---- Deleting expired token DELETE FROM one_time_token WHERE id = $1 `, resetToken.ID, ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to delete onetimetoken")) } @@ -609,9 +634,9 @@ func RequestPasswordResetSubmit(c *RequestContext) ResponseData { } if resetToken == nil { - c.Perf.StartBlock("SQL", "Creating new token") newToken, err := db.QueryOne[models.OneTimeToken](c, c.Conn, ` + ---- Creating new token INSERT INTO one_time_token (token_type, created, expires, token_content, owner_id) VALUES ($1, $2, $3, $4, $5) RETURNING $columns @@ -622,7 +647,6 @@ func RequestPasswordResetSubmit(c *RequestContext) ResponseData { models.GenerateToken(), user.ID, ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to create onetimetoken")) } @@ -723,7 +747,6 @@ func DoPasswordResetSubmit(c *RequestContext) ResponseData { hashed := auth.HashPassword(password) - c.Perf.StartBlock("SQL", "Update user's password and delete reset token") tx, err := c.Conn.Begin(c) if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to start db transaction")) @@ -732,6 +755,7 @@ func DoPasswordResetSubmit(c *RequestContext) ResponseData { tag, err := tx.Exec(c, ` + ---- Update user's password UPDATE hmn_user SET password = $1 WHERE id = $2 @@ -746,6 +770,7 @@ func DoPasswordResetSubmit(c *RequestContext) ResponseData { if validationResult.User.Status == models.UserStatusInactive { _, err = tx.Exec(c, ` + ---- Mark user as confirmed UPDATE hmn_user SET status = $1 WHERE id = $2 @@ -760,6 +785,7 @@ func DoPasswordResetSubmit(c *RequestContext) ResponseData { _, err = tx.Exec(c, ` + ---- Delete OTT DELETE FROM one_time_token WHERE id = $1 `, @@ -773,7 +799,6 @@ func DoPasswordResetSubmit(c *RequestContext) ResponseData { if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to commit password reset to the db")) } - c.Perf.EndBlock() res := c.Redirect(hmnurl.BuildUserSettings(""), http.StatusSeeOther) res.AddFutureNotice("success", "Password changed successfully.") @@ -789,8 +814,8 @@ func tryLogin(c *RequestContext, user *models.User, password string) (bool, erro return false, nil } - c.Perf.StartBlock("AUTH", "Checking password") - defer c.Perf.EndBlock() + defer c.Perf.StartBlock("AUTH", "Checking password").End() + hashed, err := auth.ParsePasswordString(user.Password) if err != nil { if user.Password == "" { @@ -811,20 +836,25 @@ func tryLogin(c *RequestContext, user *models.User, password string) (bool, erro // re-hash and save the user's password if necessary if hashed.IsOutdated() { + b := c.Perf.StartBlock("AUTH", "Re-hash password") + defer b.End() + newHashed := auth.HashPassword(password) err := auth.UpdatePassword(c, c.Conn, user.Username, newHashed) if err != nil { c.Logger.Error().Err(err).Msg("failed to update user's password") } // If errors happen here, we can still continue with logging them in + + b.End() } return true, nil } func loginUser(c *RequestContext, user *models.User, responseData *ResponseData) error { - c.Perf.StartBlock("SQL", "Setting last login and creating session") - defer c.Perf.EndBlock() + defer c.Perf.StartBlock("AUTH", "Setting last login and creating session").End() + tx, err := c.Conn.Begin(c) if err != nil { return oops.New(err, "failed to start db transaction") @@ -835,6 +865,7 @@ func loginUser(c *RequestContext, user *models.User, responseData *ResponseData) _, err = tx.Exec(c, ` + ---- Set last login UPDATE hmn_user SET last_login = $1 WHERE id = $2 @@ -880,14 +911,13 @@ type validateUserAndTokenResult struct { } func validateUsernameAndToken(c *RequestContext, username string, token string, tokenType models.OneTimeTokenType) validateUserAndTokenResult { - c.Perf.StartBlock("SQL", "Check username and token") - defer c.Perf.EndBlock() type userAndTokenQuery struct { User models.User `db:"hmn_user"` OneTimeToken *models.OneTimeToken `db:"onetimetoken"` } data, err := db.QueryOne[userAndTokenQuery](c, c.Conn, ` + ---- Load username and token SELECT $columns FROM hmn_user LEFT JOIN asset AS hmn_user_avatar ON hmn_user_avatar.id = hmn_user.avatar_asset_id @@ -928,7 +958,7 @@ func urlIsLocal(url string) bool { var reStupidUsername = regexp.MustCompile(`^[a-z]{10}$`) -func blacklist(ctx context.Context, conn db.ConnOrTx, username, email string) (bool, error) { +func isBlacklisted(ctx context.Context, conn db.ConnOrTx, username, email string) (bool, error) { if reStupidUsername.MatchString(username) { return true, nil } @@ -938,6 +968,7 @@ func blacklist(ctx context.Context, conn db.ConnOrTx, username, email string) (b count, err := db.QueryOneScalar[int](ctx, conn, ` + ---- Check blacklist SELECT count(*) FROM email_blacklist WHERE email = $1 diff --git a/src/website/blogs.go b/src/website/blogs.go index 0f2c6afb..04c36555 100644 --- a/src/website/blogs.go +++ b/src/website/blogs.go @@ -154,19 +154,18 @@ func BlogThread(c *RequestContext) ResponseData { } // Update thread last read info if c.CurrentUser != nil { - c.Perf.StartBlock("SQL", "Update TLRI") _, err := c.Conn.Exec(c, ` - INSERT INTO thread_last_read_info (thread_id, user_id, lastread) - VALUES ($1, $2, $3) - ON CONFLICT (thread_id, user_id) DO UPDATE - SET lastread = EXCLUDED.lastread - `, + ---- Update TLRI + INSERT INTO thread_last_read_info (thread_id, user_id, lastread) + VALUES ($1, $2, $3) + ON CONFLICT (thread_id, user_id) DO UPDATE + SET lastread = EXCLUDED.lastread + `, cd.ThreadID, c.CurrentUser.ID, time.Now(), ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to update blog tlri")) } @@ -250,6 +249,7 @@ func BlogNewThreadSubmit(c *RequestContext) ResponseData { var threadId int err = tx.QueryRow(c, ` + ---- Create thread INSERT INTO thread (title, type, project_id, first_id, last_id) VALUES ($1, $2, $3, $4, $5) RETURNING id @@ -362,6 +362,7 @@ func BlogPostEditSubmit(c *RequestContext) ResponseData { if title != "" { _, err := tx.Exec(c, ` + ---- Update thread title UPDATE thread SET title = $1 WHERE id = $2 `, title, @@ -547,8 +548,7 @@ type commonBlogData struct { } func getCommonBlogData(c *RequestContext) (commonBlogData, bool) { - c.Perf.StartBlock("BLOGS", "Fetch common blog data") - defer c.Perf.EndBlock() + defer c.Perf.StartBlock("BLOGS", "Fetch common blog data").End() res := commonBlogData{ c: c, @@ -561,9 +561,9 @@ func getCommonBlogData(c *RequestContext) (commonBlogData, bool) { } res.ThreadID = threadId - c.Perf.StartBlock("SQL", "Verify that the thread exists") threadExists, err := db.QueryOneScalar[bool](c, c.Conn, ` + ---- Verify that the thread exists SELECT COUNT(*) > 0 FROM thread WHERE @@ -573,7 +573,6 @@ func getCommonBlogData(c *RequestContext) (commonBlogData, bool) { res.ThreadID, c.CurrentProject.ID, ) - c.Perf.EndBlock() if err != nil { panic(err) } @@ -589,9 +588,9 @@ func getCommonBlogData(c *RequestContext) (commonBlogData, bool) { } res.PostID = postId - c.Perf.StartBlock("SQL", "Verify that the post exists") postExists, err := db.QueryOneScalar[bool](c, c.Conn, ` + ---- Verify that the post exists SELECT COUNT(*) > 0 FROM post WHERE @@ -601,7 +600,6 @@ func getCommonBlogData(c *RequestContext) (commonBlogData, bool) { res.PostID, res.ThreadID, ) - c.Perf.EndBlock() if err != nil { panic(err) } diff --git a/src/website/common.go b/src/website/common.go index 1affd8b4..5eb84ead 100644 --- a/src/website/common.go +++ b/src/website/common.go @@ -19,7 +19,7 @@ import ( func loadCommonData(h Handler) Handler { return func(c *RequestContext) ResponseData { - c.Perf.StartBlock("MIDDLEWARE", "Load common website data") + b := c.Perf.StartBlock("MIDDLEWARE", "Load common website data") { // get user { @@ -80,7 +80,7 @@ func loadCommonData(h Handler) Handler { c.UrlContext = hmndata.UrlContextForProject(c.CurrentProject) } } - c.Perf.EndBlock() + b.End() return h(c) } diff --git a/src/website/feed.go b/src/website/feed.go index e941d732..644a3d3c 100644 --- a/src/website/feed.go +++ b/src/website/feed.go @@ -151,7 +151,6 @@ func AtomFeed(c *RequestContext) ResponseData { feedData.AtomFeedUrl = hmnurl.BuildAtomFeedForProjects() feedData.FeedUrl = hmnurl.BuildProjectIndex() - c.Perf.StartBlock("SQL", "Fetching projects") _, hasAll := c.Req.URL.Query()["all"] if hasAll { itemsPerFeed = 100000 @@ -173,7 +172,6 @@ func AtomFeed(c *RequestContext) ResponseData { feedData.Projects = append(feedData.Projects, templateProject) } - c.Perf.EndBlock() updated := time.Now() if len(feedData.Projects) > 0 { @@ -200,12 +198,10 @@ func fetchAllPosts(c *RequestContext, offset int, limit int) ([]templates.PostLi if err != nil { return nil, err } - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() - c.Perf.StartBlock("FEED", "Build post items") + b := c.Perf.StartBlock("FEED", "Build post items") var postItems []templates.PostListItem for _, postAndStuff := range postsAndStuff { postItem := MakePostListItem( @@ -223,7 +219,7 @@ func fetchAllPosts(c *RequestContext, offset int, limit int) ([]templates.PostLi postItems = append(postItems, postItem) } - c.Perf.EndBlock() + b.End() return postItems, nil } diff --git a/src/website/following.go b/src/website/following.go index 3700bfa5..2f486067 100644 --- a/src/website/following.go +++ b/src/website/following.go @@ -11,10 +11,8 @@ import ( ) func FollowingTest(c *RequestContext) ResponseData { - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() timelineItems, err := FetchFollowTimelineForUser( c, c.Conn, diff --git a/src/website/forums.go b/src/website/forums.go index 9ab425ce..33e95563 100644 --- a/src/website/forums.go +++ b/src/website/forums.go @@ -207,10 +207,8 @@ func Forum(c *RequestContext) ResponseData { } func ForumMarkRead(c *RequestContext) ResponseData { - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() sfId, err := strconv.Atoi(c.PathParams["sfid"]) if err != nil { @@ -262,42 +260,40 @@ func ForumMarkRead(c *RequestContext) ResponseData { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to delete subforum unread info")) } } else { - c.Perf.StartBlock("SQL", "Update SLRIs") _, err = tx.Exec(c, ` - INSERT INTO subforum_last_read_info (subforum_id, user_id, lastread) - SELECT id, $2, $3 - FROM subforum - WHERE id = ANY ($1) - ON CONFLICT (subforum_id, user_id) DO UPDATE - SET lastread = EXCLUDED.lastread - `, + ---- Update SLRIs + INSERT INTO subforum_last_read_info (subforum_id, user_id, lastread) + SELECT id, $2, $3 + FROM subforum + WHERE id = ANY ($1) + ON CONFLICT (subforum_id, user_id) DO UPDATE + SET lastread = EXCLUDED.lastread + `, sfIds, c.CurrentUser.ID, time.Now(), ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to update forum slris")) } - c.Perf.StartBlock("SQL", "Delete TLRIs") _, err = tx.Exec(c, ` - DELETE FROM thread_last_read_info - WHERE - user_id = $2 - AND thread_id IN ( - SELECT id - FROM thread - WHERE - subforum_id = ANY ($1) - ) - `, + ---- Delete TLRIs + DELETE FROM thread_last_read_info + WHERE + user_id = $2 + AND thread_id IN ( + SELECT id + FROM thread + WHERE + subforum_id = ANY ($1) + ) + `, sfIds, c.CurrentUser.ID, ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to delete unnecessary tlris")) } @@ -410,9 +406,9 @@ func ForumThread(c *RequestContext) ResponseData { // Update thread last read info if c.CurrentUser != nil { - c.Perf.StartBlock("SQL", "Update TLRI") _, err = c.Conn.Exec(c, ` + ---- Update TLRI INSERT INTO thread_last_read_info (thread_id, user_id, lastread) VALUES ($1, $2, $3) ON CONFLICT (thread_id, user_id) DO UPDATE @@ -422,7 +418,6 @@ func ForumThread(c *RequestContext) ResponseData { c.CurrentUser.ID, time.Now(), ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to update forum tlri")) } @@ -850,10 +845,8 @@ func WikiArticleRedirect(c *RequestContext) ResponseData { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to look up wiki thread")) } - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() dest := UrlForGenericThread(c.UrlContext, &thread.Thread, lineageBuilder) return c.Redirect(dest, http.StatusFound) @@ -879,13 +872,10 @@ Does NOT validate that the requested thread and post ID are valid. If this returns false, then something was malformed and you should 404. */ func getCommonForumData(c *RequestContext) (commonForumData, bool) { - c.Perf.StartBlock("FORUMS", "Fetch common forum data") - defer c.Perf.EndBlock() + defer c.Perf.StartBlock("FORUMS", "Fetch common forum data").End() - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() res := commonForumData{ c: c, diff --git a/src/website/imagefile_helper.go b/src/website/imagefile_helper.go index 38c7e654..4bb92f0a 100644 --- a/src/website/imagefile_helper.go +++ b/src/website/imagefile_helper.go @@ -44,14 +44,15 @@ func SaveImageFile(c *RequestContext, dbConn db.ConnOrTx, fileFieldName string, ValidationError: fmt.Sprintf("Image filesize too big. Max size: %d bytes", maxSize), } } else { - c.Perf.StartBlock("IMAGE", "Decoding image") + b := c.Perf.StartBlock("IMAGE", "Decoding image") config, format, err := image.DecodeConfig(img) - c.Perf.EndBlock() + b.End() if err != nil { return SaveImageFileResult{ ValidationError: "Image type not supported", } } + width = config.Width height = config.Height if width == 0 || height == 0 { @@ -62,28 +63,31 @@ func SaveImageFile(c *RequestContext, dbConn db.ConnOrTx, fileFieldName string, filename = fmt.Sprintf("%s.%s", filepath, format) storageFilename := fmt.Sprintf("public/media/%s", filename) - c.Perf.StartBlock("IMAGE", "Writing image file") - file, err := os.Create(storageFilename) - if err != nil { - return SaveImageFileResult{ - FatalError: oops.New(err, "Failed to create local image file"), + { + b := c.Perf.StartBlock("IMAGE", "Writing image file") + defer b.End() + + file, err := os.Create(storageFilename) + if err != nil { + return SaveImageFileResult{ + FatalError: oops.New(err, "Failed to create local image file"), + } } - } - img.Seek(0, io.SeekStart) - _, err = io.Copy(file, img) - if err != nil { - return SaveImageFileResult{ - FatalError: oops.New(err, "Failed to write image to file"), + img.Seek(0, io.SeekStart) + _, err = io.Copy(file, img) + if err != nil { + return SaveImageFileResult{ + FatalError: oops.New(err, "Failed to write image to file"), + } } + file.Close() + img.Close() + + b.End() } - file.Close() - img.Close() - c.Perf.EndBlock() } } - c.Perf.EndBlock() - c.Perf.StartBlock("SQL", "Saving image file") if filename != "" { hasher := sha1.New() img.Seek(0, io.SeekStart) @@ -91,6 +95,7 @@ func SaveImageFile(c *RequestContext, dbConn db.ConnOrTx, fileFieldName string, sha1sum := hasher.Sum(nil) imageFile, err := db.QueryOne[models.ImageFile](c, dbConn, ` + ---- Save image file INSERT INTO image_file (file, size, sha1sum, protected, width, height) VALUES ($1, $2, $3, $4, $5, $6) RETURNING $columns diff --git a/src/website/jam.go b/src/website/jam.go index ba76d023..5be95c4a 100644 --- a/src/website/jam.go +++ b/src/website/jam.go @@ -1294,11 +1294,10 @@ func JamIndex2021(c *RequestContext) ResponseData { showcaseItems = append(showcaseItems, timelineItem) } } - c.Perf.EndBlock() - c.Perf.StartBlock("SHOWCASE", "Convert to json") + b := c.Perf.StartBlock("SHOWCASE", "Convert to json") showcaseJson := templates.TimelineItemsToJSON(showcaseItems) - c.Perf.EndBlock() + b.End() baseData := getBaseDataAutocrumb(c, hmndata.WRJ2021.Name) baseData.OpenGraphItems = []templates.OpenGraphItem{ diff --git a/src/website/landing.go b/src/website/landing.go index 41cb8609..b56e8b7b 100644 --- a/src/website/landing.go +++ b/src/website/landing.go @@ -17,10 +17,8 @@ func Index(c *RequestContext) ResponseData { const maxPostsPerTab = 20 const maxNewsPosts = 10 - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() type LandingTemplateData struct { templates.BaseData diff --git a/src/website/perfmon.go b/src/website/perfmon.go index c7c5c726..9a3a7399 100644 --- a/src/website/perfmon.go +++ b/src/website/perfmon.go @@ -10,9 +10,9 @@ import ( ) func Perfmon(c *RequestContext) ResponseData { - c.Perf.StartBlock("PERF", "Requesting perf data") + b := c.Perf.StartBlock("PERF", "Requesting perf data") perfData := c.PerfCollector.GetPerfCopy() - c.Perf.EndBlock() + b.End() type FlameItem struct { Offset int64 @@ -36,53 +36,58 @@ func Perfmon(c *RequestContext) ResponseData { PerfRecordsJSON string } - perfRecords := []PerfRecord{} + var perfJSON []byte + { + b := c.Perf.StartBlock("PERF", "Processing perf data") + defer b.End() - c.Perf.StartBlock("PERF", "Processing perf data") - for _, item := range perfData.AllRequests { - record := PerfRecord{ - Route: item.Route, - Path: item.Path, - Duration: item.End.Sub(item.Start).Microseconds(), - Breakdown: &FlameItem{ - Offset: 0, + perfRecords := []PerfRecord{} + for _, item := range perfData.AllRequests { + record := PerfRecord{ + Route: item.Route, + Path: item.Path, Duration: item.End.Sub(item.Start).Microseconds(), - End: item.End, - }, - } - - parent := record.Breakdown - for _, block := range item.Blocks { - for parent.Parent != nil && block.End.After(parent.End) { - parent = parent.Parent + Breakdown: &FlameItem{ + Offset: 0, + Duration: item.End.Sub(item.Start).Microseconds(), + End: item.End, + }, } - flame := FlameItem{ - Offset: block.Start.Sub(item.Start).Microseconds(), - Duration: block.End.Sub(block.Start).Microseconds(), - Category: block.Category, - Description: block.Description, - End: block.End, - Parent: parent, + + parent := record.Breakdown + for _, block := range item.Blocks { + for parent.Parent != nil && block.End.After(parent.End) { + parent = parent.Parent + } + flame := FlameItem{ + Offset: block.Start.Sub(item.Start).Microseconds(), + Duration: block.End.Sub(block.Start).Microseconds(), + Category: block.Category, + Description: block.Description, + End: block.End, + Parent: parent, + } + + parent.Children = append(parent.Children, &flame) + parent = &flame } - parent.Children = append(parent.Children, &flame) - parent = &flame + perfRecords = append(perfRecords, record) } - perfRecords = append(perfRecords, record) - } + var err error + perfJSON, err = json.Marshal(perfRecords) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to marshal json")) + } - json, err := json.Marshal(perfRecords) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to marshal json")) + b.End() } - c.Perf.EndBlock() - var res ResponseData res.MustWriteTemplate("perfmon.html", PerfmonData{ BaseData: getBaseDataAutocrumb(c, "Perfmon"), - PerfRecordsJSON: string(json), + PerfRecordsJSON: string(perfJSON), }, c.Perf) return res } diff --git a/src/website/podcast.go b/src/website/podcast.go index 04ec6c29..cc454733 100644 --- a/src/website/podcast.go +++ b/src/website/podcast.go @@ -112,13 +112,21 @@ func PodcastEditSubmit(c *RequestContext) ResponseData { return FourOhFour(c) } - c.Perf.StartBlock("PODCAST", "Handling file upload") - c.Perf.StartBlock("PODCAST", "Parsing form") - maxFileSize := int64(2 * 1024 * 1024) - maxBodySize := maxFileSize + 1024*1024 - c.Req.Body = http.MaxBytesReader(c.Res, c.Req.Body, maxBodySize) - err = c.Req.ParseMultipartForm(maxBodySize) - c.Perf.EndBlock() + defer c.Perf.StartBlock("PODCAST", "Handling file upload").End() + + var maxFileSize int64 + { + b := c.Perf.StartBlock("PODCAST", "Parsing form") + defer b.End() + + maxFileSize = int64(2 * 1024 * 1024) + maxBodySize := maxFileSize + 1024*1024 + c.Req.Body = http.MaxBytesReader(c.Res, c.Req.Body, maxBodySize) + err = c.Req.ParseMultipartForm(maxBodySize) + + b.End() + } + if err != nil { // NOTE(asaf): The error for exceeding the max filesize doesn't have a special type, so we can't easily detect it here. return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to parse form")) @@ -180,7 +188,6 @@ func PodcastEditSubmit(c *RequestContext) ResponseData { ) } err = tx.Commit(c) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to commit db transaction")) } @@ -347,9 +354,7 @@ func PodcastEpisodeSubmit(c *RequestContext) ResponseData { return FourOhFour(c) } - c.Perf.StartBlock("OS", "Fetching podcast episode files") episodeFiles, err := GetEpisodeFiles(c.CurrentProject.Slug) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to fetch podcast episode file list")) } @@ -381,44 +386,49 @@ func PodcastEpisodeSubmit(c *RequestContext) ResponseData { return c.RejectRequest("Requested episode file not found") } - c.Perf.StartBlock("MP3", "Parsing mp3 file for duration") - file, err := os.Open(fmt.Sprintf("public/media/podcast/%s/%s", c.CurrentProject.Slug, episodeFile)) - if err != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to open podcast file")) - } - - mp3Decoder := mp3.NewDecoder(file) var duration float64 - skipped := 0 - var decodingError error - var f mp3.Frame - for { - if err = mp3Decoder.Decode(&f, &skipped); err != nil { - if err == io.EOF { - break - } else { - decodingError = err - break + { + b := c.Perf.StartBlock("MP3", "Parsing mp3 file for duration") + defer b.End() + + file, err := os.Open(fmt.Sprintf("public/media/podcast/%s/%s", c.CurrentProject.Slug, episodeFile)) + if err != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to open podcast file")) + } + + mp3Decoder := mp3.NewDecoder(file) + skipped := 0 + var decodingError error + var f mp3.Frame + for { + if err = mp3Decoder.Decode(&f, &skipped); err != nil { + if err == io.EOF { + break + } else { + decodingError = err + break + } } + duration = duration + f.Duration().Seconds() } - duration = duration + f.Duration().Seconds() - } - file.Close() - c.Perf.EndBlock() - if decodingError != nil { - return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to decode mp3 file")) + file.Close() + if decodingError != nil { + return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to decode mp3 file")) + } + + b.End() } - c.Perf.StartBlock("MARKDOWN", "Parsing description") + b := c.Perf.StartBlock("MARKDOWN", "Parsing description") descriptionRendered := parsing.ParseMarkdown(description, parsing.ForumRealMarkdown) - c.Perf.EndBlock() + b.End() guidStr := "" if isEdit { guidStr = podcastResult.Episodes[0].GUID.String() - c.Perf.StartBlock("SQL", "Updating podcast episode") _, err := c.Conn.Exec(c, ` + ---- Update podcast episode UPDATE podcast_episode SET title = $1, @@ -438,16 +448,15 @@ func PodcastEpisodeSubmit(c *RequestContext) ResponseData { episodeNumber, podcastResult.Episodes[0].GUID, ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to update podcast episode")) } } else { guid := uuid.New() guidStr = guid.String() - c.Perf.StartBlock("SQL", "Creating new podcast episode") _, err := c.Conn.Exec(c, ` + ---- Creating new podcast episode INSERT INTO podcast_episode (guid, title, description, description_rendered, audio_filename, duration, pub_date, episode_number, podcast_id) VALUES @@ -463,7 +472,6 @@ func PodcastEpisodeSubmit(c *RequestContext) ResponseData { episodeNumber, podcastResult.Podcast.ID, ) - c.Perf.EndBlock() if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "Failed to create podcast episode")) } @@ -527,13 +535,13 @@ type PodcastResult struct { func FetchPodcast(c *RequestContext, projectId int, fetchEpisodes bool, episodeGUID string) (PodcastResult, error) { var result PodcastResult - c.Perf.StartBlock("SQL", "Fetch podcast") type podcastQuery struct { Podcast models.Podcast `db:"podcast"` ImageFilename string `db:"imagefile.file"` } podcastQueryResult, err := db.QueryOne[podcastQuery](c, c.Conn, ` + ---- Fetch podcast SELECT $columns FROM podcast @@ -542,7 +550,6 @@ func FetchPodcast(c *RequestContext, projectId int, fetchEpisodes bool, episodeG `, projectId, ) - c.Perf.EndBlock() if err != nil { if errors.Is(err, db.NotFound) { return result, nil @@ -557,9 +564,9 @@ func FetchPodcast(c *RequestContext, projectId int, fetchEpisodes bool, episodeG if fetchEpisodes { if episodeGUID == "" { - c.Perf.StartBlock("SQL", "Fetch podcast episodes") episodes, err := db.Query[models.PodcastEpisode](c, c.Conn, ` + ---- Fetch podcast episodes SELECT $columns FROM podcast_episode AS episode WHERE episode.podcast_id = $1 @@ -567,7 +574,6 @@ func FetchPodcast(c *RequestContext, projectId int, fetchEpisodes bool, episodeG `, podcast.ID, ) - c.Perf.EndBlock() if err != nil { return result, oops.New(err, "failed to fetch podcast episodes") } @@ -577,9 +583,9 @@ func FetchPodcast(c *RequestContext, projectId int, fetchEpisodes bool, episodeG if err != nil { return result, err } - c.Perf.StartBlock("SQL", "Fetch podcast episode") episode, err := db.QueryOne[models.PodcastEpisode](c, c.Conn, ` + ---- Fetch podcast episode SELECT $columns FROM podcast_episode AS episode WHERE episode.podcast_id = $1 AND episode.guid = $2 @@ -587,7 +593,6 @@ func FetchPodcast(c *RequestContext, projectId int, fetchEpisodes bool, episodeG podcast.ID, guid, ) - c.Perf.EndBlock() if err != nil { if errors.Is(err, db.NotFound) { return result, nil diff --git a/src/website/projects.go b/src/website/projects.go index 00f7485b..120e150e 100644 --- a/src/website/projects.go +++ b/src/website/projects.go @@ -63,7 +63,8 @@ func getShuffledOfficialProjects(c *RequestContext) ([]templates.Project, error) return nil, oops.New(err, "failed to fetch projects") } - c.Perf.StartBlock("PROJECTS", "Grouping and sorting") + defer c.Perf.StartBlock("PROJECT", "Grouping and sorting").End() + var handmadeHero hmndata.ProjectAndStuff var featuredProjects []hmndata.ProjectAndStuff var restProjects []hmndata.ProjectAndStuff @@ -99,8 +100,6 @@ func getShuffledOfficialProjects(c *RequestContext) ([]templates.Project, error) projects = append(projects, templates.ProjectAndStuffToTemplate(&p)) } - c.Perf.EndBlock() - return projects, nil } @@ -177,9 +176,9 @@ func ProjectHomepage(c *RequestContext) ResponseData { return c.ErrorResponse(http.StatusInternalServerError, err) } - c.Perf.StartBlock("SQL", "Fetching screenshots") screenshotFilenames, err := db.QueryScalar[string](c, c.Conn, ` + ---- Fetching screenshots SELECT screenshot.file FROM image_file AS screenshot @@ -192,11 +191,10 @@ func ProjectHomepage(c *RequestContext) ResponseData { if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch screenshots for project")) } - c.Perf.EndBlock() - c.Perf.StartBlock("SQL", "Fetching project links") projectLinks, err := db.Query[models.Link](c, c.Conn, ` + ---- Fetching project links SELECT $columns FROM link as link @@ -209,7 +207,6 @@ func ProjectHomepage(c *RequestContext) ResponseData { if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch project links")) } - c.Perf.EndBlock() type ProjectHomepageData struct { templates.BaseData @@ -301,10 +298,8 @@ func ProjectHomepage(c *RequestContext) ResponseData { } } - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() templateData.RecentActivity, err = FetchTimeline(c, c.Conn, c.CurrentUser, lineageBuilder, hmndata.TimelineQuery{ ProjectIDs: []int{c.CurrentProject.ID}, @@ -512,9 +507,9 @@ func ProjectEdit(c *RequestContext) ResponseData { return c.ErrorResponse(http.StatusInternalServerError, err) } - c.Perf.StartBlock("SQL", "Fetching project links") projectLinks, err := db.Query[models.Link](c, c.Conn, ` + ---- Fetching project links SELECT $columns FROM link as link @@ -527,14 +522,11 @@ func ProjectEdit(c *RequestContext) ResponseData { if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch project links")) } - c.Perf.EndBlock() - c.Perf.StartBlock("SQL", "Fetching project jams") projectJams, err := hmndata.FetchJamsForProject(c, c.Conn, c.CurrentUser, p.Project.ID) if err != nil { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch jams for project")) } - c.Perf.EndBlock() projectSettings := templates.ProjectToProjectSettings( &p.Project, diff --git a/src/website/requesthandling.go b/src/website/requesthandling.go index f7d926a0..4df10bce 100644 --- a/src/website/requesthandling.go +++ b/src/website/requesthandling.go @@ -446,8 +446,8 @@ func (rd *ResponseData) AddFutureNotice(class string, content string) { func (rd *ResponseData) WriteTemplate(name string, data interface{}, rp *perf.RequestPerf) error { if rp != nil { - rp.StartBlock("TEMPLATE", name) - defer rp.EndBlock() + b := rp.StartBlock("TEMPLATE", name) + defer b.End() } return templates.GetTemplate(name).Execute(rd, data) } diff --git a/src/website/snippet.go b/src/website/snippet.go index aa2daa0e..f305a059 100644 --- a/src/website/snippet.go +++ b/src/website/snippet.go @@ -21,7 +21,6 @@ import ( "git.handmade.network/hmn/hmn/src/parsing" "git.handmade.network/hmn/hmn/src/templates" "github.com/google/uuid" - "mvdan.cc/xurls/v2" ) @@ -54,7 +53,6 @@ func Snippet(c *RequestContext) ResponseData { return c.ErrorResponse(http.StatusInternalServerError, oops.New(err, "failed to fetch snippet")) } } - c.Perf.EndBlock() canEdit := (c.CurrentUser != nil && (c.CurrentUser.IsStaff || c.CurrentUser.ID == s.Owner.ID)) snippet := SnippetToTimelineItem(&s.Snippet, s.Asset, s.DiscordMessage, s.Projects, s.Owner, canEdit) diff --git a/src/website/timeline_helper.go b/src/website/timeline_helper.go index 925f3e2e..f2c5494a 100644 --- a/src/website/timeline_helper.go +++ b/src/website/timeline_helper.go @@ -26,14 +26,16 @@ type FollowTimelineQuery struct { } func FetchFollowTimelineForUser(ctx context.Context, conn db.ConnOrTx, user *models.User, lineageBuilder *models.SubforumLineageBuilder, q FollowTimelineQuery) ([]templates.TimelineItem, error) { - perf := perf.ExtractPerf(ctx) + defer perf.StartBlock(ctx, "FOLLOW", "Assemble follow data").End() - perf.StartBlock("FOLLOW", "Assemble follow data") - following, err := db.Query[models.Follow](ctx, conn, ` + following, err := db.Query[models.Follow](ctx, conn, + ` SELECT $columns FROM follower WHERE user_id = $1 - `, user.ID) + `, + user.ID, + ) if err != nil { return nil, oops.New(err, "failed to fetch follow data") @@ -59,7 +61,6 @@ func FetchFollowTimelineForUser(ctx context.Context, conn db.ConnOrTx, user *mod Limit: q.Limit, }) } - perf.EndBlock() return timelineItems, err } @@ -82,10 +83,10 @@ func FetchTimeline(ctx context.Context, conn db.ConnOrTx, currentUser *models.Us } func FetchFollows(ctx context.Context, conn db.ConnOrTx, currentUser *models.User, userID int) ([]templates.Follow, error) { - perf := perf.ExtractPerf(ctx) + defer perf.StartBlock(ctx, "FOLLOW", "Fetch follows") - perf.StartBlock("SQL", "Fetch follows") following, err := db.Query[models.Follow](ctx, conn, ` + ---- Fetch follows SELECT $columns FROM follower WHERE user_id = $1 @@ -93,7 +94,6 @@ func FetchFollows(ctx context.Context, conn db.ConnOrTx, currentUser *models.Use if err != nil { return nil, oops.New(err, "failed to fetch follows") } - perf.EndBlock() var userIDs, projectIDs []int for _, follow := range following { diff --git a/src/website/user.go b/src/website/user.go index 570725e9..45b333db 100644 --- a/src/website/user.go +++ b/src/website/user.go @@ -77,9 +77,9 @@ func UserProfile(c *RequestContext) ResponseData { } } - c.Perf.StartBlock("SQL", "Fetch user links") userLinks, err := db.Query[models.Link](c, c.Conn, ` + ---- Fetch user links SELECT $columns FROM link as link @@ -96,7 +96,6 @@ func UserProfile(c *RequestContext) ResponseData { for _, l := range userLinks { profileUserLinks = append(profileUserLinks, templates.LinkToTemplate(l)) } - c.Perf.EndBlock() projectsAndStuff, err := hmndata.FetchProjects(c, c.Conn, c.CurrentUser, hmndata.ProjectsQuery{ OwnerIDs: []int{profileUser.ID}, @@ -114,12 +113,9 @@ func UserProfile(c *RequestContext) ResponseData { numPersonalProjects++ } } - c.Perf.EndBlock() - c.Perf.StartBlock("SQL", "Fetch subforum tree") subforumTree := models.GetFullSubforumTree(c, c.Conn) lineageBuilder := models.MakeSubforumLineageBuilder(subforumTree) - c.Perf.EndBlock() timelineItems, err := FetchTimeline(c, c.Conn, c.CurrentUser, lineageBuilder, hmndata.TimelineQuery{ OwnerIDs: []int{profileUser.ID}, diff --git a/src/website/website.go b/src/website/website.go index 50bc9e6c..19f414e6 100644 --- a/src/website/website.go +++ b/src/website/website.go @@ -38,8 +38,8 @@ var WebsiteCommand = &cobra.Command{ var wg sync.WaitGroup - conn := db.NewConnPool() perfCollector, perfCollectorJob := perf.RunPerfCollector() + conn := db.NewConnPool() // Start background jobs wg.Add(1)