From 1958a8573ff20be82528d951f19aaf367b8cf839 Mon Sep 17 00:00:00 2001 From: zkldi <20380519+zkldi@users.noreply.github.com> Date: Thu, 11 Nov 2021 01:20:45 +0000 Subject: [PATCH] Automatically deorphan score children on chart deorphaning, and fix multiple bugs with the deorphaning flow. --- server/src/lib/orphan-queue/orphan-queue.ts | 4 +- .../framework/orphans/orphans.test.ts | 4 + .../score-import/framework/orphans/orphans.ts | 38 +++- .../framework/pb/create-pb-doc.ts | 11 +- .../framework/score-import-main.ts | 204 ++++++++++-------- .../score-importing/score-importing.ts | 50 +++-- .../score-import/import-types/common/types.ts | 2 + .../router/api/v1/import/router.test.ts | 2 + .../src/server/router/ir/beatoraja/router.ts | 9 +- server/src/server/router/ir/usc/router.ts | 4 +- 10 files changed, 215 insertions(+), 113 deletions(-) diff --git a/server/src/lib/orphan-queue/orphan-queue.ts b/server/src/lib/orphan-queue/orphan-queue.ts index ddc66a559..4a44eb7a4 100644 --- a/server/src/lib/orphan-queue/orphan-queue.ts +++ b/server/src/lib/orphan-queue/orphan-queue.ts @@ -65,9 +65,7 @@ export async function HandleOrphanQueue( // If N or more people have played this chart while orphaned, unorphan // it. if (playcount >= queueSize) { - logger.info( - `Song ${chartName} was unorphaned by ${uniqueUsersArr.join(", ")} and ${userID}.` - ); + logger.info(`Song ${chartName} was unorphaned by userIDs ${uniqueUsersArr.join(", ")}.`); const songID = await GetNextCounterValue(`${game}-song-id`); logger.verbose(`${chartName} has been assigned songID ${songID}.`); diff --git a/server/src/lib/score-import/framework/orphans/orphans.test.ts b/server/src/lib/score-import/framework/orphans/orphans.test.ts index 932436ea4..bf81e6d26 100644 --- a/server/src/lib/score-import/framework/orphans/orphans.test.ts +++ b/server/src/lib/score-import/framework/orphans/orphans.test.ts @@ -37,6 +37,7 @@ t.test("#OrphanScore", (t) => { batchManualScore, batchManualContext, "Example Error Message", + "iidx", logger ); @@ -83,6 +84,7 @@ t.test("#OrphanScore", (t) => { batchManualScore, batchManualContext, "Example Error Message", + "iidx", logger ); @@ -92,6 +94,7 @@ t.test("#OrphanScore", (t) => { batchManualScore, batchManualContext, "Example Error Message", + "iidx", logger ); @@ -116,6 +119,7 @@ t.test("#ReprocessOrphan", (t) => { importType: "ir/direct-manual", orphanID: "foo", timeInserted: 0, + game: "iidx", userID: 1, }; diff --git a/server/src/lib/score-import/framework/orphans/orphans.ts b/server/src/lib/score-import/framework/orphans/orphans.ts index 68951398a..b3a263c82 100644 --- a/server/src/lib/score-import/framework/orphans/orphans.ts +++ b/server/src/lib/score-import/framework/orphans/orphans.ts @@ -6,7 +6,7 @@ import { ImportTypeDataMap, OrphanScoreDocument, } from "../../import-types/common/types"; -import { ImportTypes, integer } from "tachi-common"; +import { Game, ImportTypes, integer } from "tachi-common"; import fjsh from "fast-json-stable-hash"; import { KtLogger } from "lib/logger/logger"; import { Converters } from "../../import-types/converters"; @@ -16,6 +16,8 @@ import { KTDataNotFoundFailure, } from "../common/converter-failures"; import { ProcessSuccessfulConverterReturn } from "../score-importing/score-importing"; +import { HandlePostImportSteps } from "../score-import-main"; +import { GetUserWithID } from "utils/user"; /** * Creates an OrphanedScore document from the data and context, @@ -29,6 +31,7 @@ export async function OrphanScore( data: ImportTypeDataMap[T], context: ImportTypeContextMap[T], errMsg: string | null, + game: Game, logger: KtLogger ) { const orphan: Pick = { @@ -50,6 +53,7 @@ export async function OrphanScore( const orphanScoreDoc: OrphanScoreDocument = { ...orphan, orphanID, + game, errMsg, timeInserted: Date.now(), }; @@ -117,5 +121,35 @@ export async function ReprocessOrphan( await db["orphan-scores"].remove({ orphanID: orphan.orphanID }); // else, import the orphan. - return ProcessSuccessfulConverterReturn(orphan.userID, res, blacklist, logger); + const converterReturns = await ProcessSuccessfulConverterReturn( + orphan.userID, + res, + blacklist, + logger, + true + ); + + if (converterReturns === null || !converterReturns.success) { + return null; + } + + const user = await GetUserWithID(orphan.userID); + + if (!user) { + logger.severe( + `Orphan ${orphan.orphanID} belongs to ${orphan.userID}, but that user no longer exists in the database. Going to skip this and remove the orphan.` + ); + return null; + } + + await HandlePostImportSteps( + [converterReturns], + user, + orphan.importType, + orphan.game, + null, + logger + ); + + return converterReturns; } diff --git a/server/src/lib/score-import/framework/pb/create-pb-doc.ts b/server/src/lib/score-import/framework/pb/create-pb-doc.ts index 077a77e0b..2317f3198 100644 --- a/server/src/lib/score-import/framework/pb/create-pb-doc.ts +++ b/server/src/lib/score-import/framework/pb/create-pb-doc.ts @@ -20,10 +20,13 @@ export async function CreatePBDoc(userID: integer, chartID: string, logger: KtLo ); if (!scorePB) { - logger.severe(`User has no scores on chart, but a PB was attempted to be created?`, { - chartID, - userID, - }); + logger.severe( + `User ${userID} has no scores on chart, but a PB was attempted to be created?`, + { + chartID, + userID, + } + ); return; } diff --git a/server/src/lib/score-import/framework/score-import-main.ts b/server/src/lib/score-import/framework/score-import-main.ts index 0608995cf..071b3819c 100644 --- a/server/src/lib/score-import/framework/score-import-main.ts +++ b/server/src/lib/score-import/framework/score-import-main.ts @@ -89,6 +89,7 @@ export default async function ScoreImportMain( iterable, ConverterFunction, context, + game, logger ); @@ -97,90 +98,24 @@ export default async function ScoreImportMain( logger.debug(`Importing took ${importTime} miliseconds. (${importTimeRel}ms/doc)`); - // --- 3. ParseImportInfo --- - // ImportInfo is a relatively complex structure. We need some information from it for subsequent steps - // such as the list of chartIDs involved in this import. - const importParseTimeStart = process.hrtime.bigint(); - const { scorePlaytypeMap, errors, scoreIDs, chartIDs } = ParseImportInfo(importInfo); - - const importParseTime = GetMilisecondsSince(importParseTimeStart); - const importParseTimeRel = importParseTime / importInfo.length; - - logger.debug( - `Import Parsing took ${importParseTime} miliseconds. (${importParseTimeRel}ms/doc)` - ); - - // --- 4. Sessions --- - // We create (or update existing) sessions here. This uses the aforementioned parsed import info - // to determine what goes where. - const sessionTimeStart = process.hrtime.bigint(); - const sessionInfo = await CreateSessions( - user.id, - importType, - game, - scorePlaytypeMap, - logger - ); - - const sessionTime = GetMilisecondsSince(sessionTimeStart); - const sessionTimeRel = sessionTime / sessionInfo.length; - - logger.debug( - `Session Processing took ${sessionTime} miliseconds (${sessionTimeRel}ms/doc).` - ); - - // --- 5. PersonalBests --- - // We want to keep an updated reference of a users best score on a given chart. - // This function also handles conjoining different scores together (such as unioning best lamp and - // best score). - const pbTimeStart = process.hrtime.bigint(); - await ProcessPBs(user.id, chartIDs, logger); - - const pbTime = GetMilisecondsSince(pbTimeStart); - const pbTimeRel = pbTime / chartIDs.size; - - logger.debug(`PB Processing took ${pbTime} miliseconds (${pbTimeRel}ms/doc)`); - - const playtypes = Object.keys(scorePlaytypeMap) as Playtypes[Game][]; - - // --- 6. Game Stats --- - // This function updates the users "stats" for this game - such as their profile rating or their classes. - const ugsTimeStart = process.hrtime.bigint(); - const classDeltas = await UpdateUsersGameStats( - game, + // Steps 3-8 are handled inside here. + // This was moved inside here so the score de-orphaning process + // could hook into importing better + const { playtypes, - user.id, - classHandler, - logger - ); - - const ugsTime = GetMilisecondsSince(ugsTimeStart); - - logger.debug(`UGS Processing took ${ugsTime} miliseconds.`); - - // --- 7. Goals --- - // Evaluate and update the users goals. This returns information about goals that have changed. - const goalTimeStart = process.hrtime.bigint(); - const goalInfo = await GetAndUpdateUsersGoals(game, user.id, chartIDs, logger); - - const goalTime = GetMilisecondsSince(goalTimeStart); - - logger.debug(`Goal Processing took ${goalTime} miliseconds.`); - - // --- 8. Milestones --- - // Evaluate and update the users milestones. This returns... - const milestoneTimeStart = process.hrtime.bigint(); - const milestoneInfo = await UpdateUsersMilestones( + scoreIDs, + errors, + sessionInfo, + classDeltas, goalInfo, - game, - playtypes, - user.id, - logger - ); + milestoneInfo, + relativeTimes, + absoluteTimes, + } = await HandlePostImportSteps(importInfo, user, importType, game, classHandler, logger); - const milestoneTime = GetMilisecondsSince(milestoneTimeStart); - - logger.debug(`Milestone Processing took ${milestoneTime} miliseconds.`); + const { importParseTimeRel, pbTimeRel, sessionTimeRel } = relativeTimes; + const { importParseTime, sessionTime, pbTime, ugsTime, goalTime, milestoneTime } = + absoluteTimes; // --- 9. Finalise Import Document --- // Create and Save an import document to the database, and finish everything up! @@ -243,15 +178,114 @@ export default async function ScoreImportMain( }, }); - await RemoveUserLock(user.id); - return ImportDocument; - } catch (err) { + } finally { await RemoveUserLock(user.id); - throw err; } } +/** + * Handles every single processing step after actually loading scores + * into the database, such as updating goals, reprocessing sessions, + * and updating a users game stats. + */ +export async function HandlePostImportSteps( + importInfo: ImportProcessingInfo[], + user: PublicUserDocument, + importType: ImportTypes, + game: Game, + classHandler: ClassHandler | null, + logger: KtLogger +) { + // --- 3. ParseImportInfo --- + // ImportInfo is a relatively complex structure. We need some information from it for subsequent steps + // such as the list of chartIDs involved in this import. + const importParseTimeStart = process.hrtime.bigint(); + const { scorePlaytypeMap, errors, scoreIDs, chartIDs } = ParseImportInfo(importInfo); + + const importParseTime = GetMilisecondsSince(importParseTimeStart); + const importParseTimeRel = importParseTime / importInfo.length; + + logger.debug( + `Import Parsing took ${importParseTime} miliseconds. (${importParseTimeRel}ms/doc)` + ); + + // --- 4. Sessions --- + // We create (or update existing) sessions here. This uses the aforementioned parsed import info + // to determine what goes where. + const sessionTimeStart = process.hrtime.bigint(); + const sessionInfo = await CreateSessions(user.id, importType, game, scorePlaytypeMap, logger); + + const sessionTime = GetMilisecondsSince(sessionTimeStart); + const sessionTimeRel = sessionTime / sessionInfo.length; + + logger.debug(`Session Processing took ${sessionTime} miliseconds (${sessionTimeRel}ms/doc).`); + + // --- 5. PersonalBests --- + // We want to keep an updated reference of a users best score on a given chart. + // This function also handles conjoining different scores together (such as unioning best lamp and + // best score). + const pbTimeStart = process.hrtime.bigint(); + await ProcessPBs(user.id, chartIDs, logger); + + const pbTime = GetMilisecondsSince(pbTimeStart); + const pbTimeRel = pbTime / chartIDs.size; + + logger.debug(`PB Processing took ${pbTime} miliseconds (${pbTimeRel}ms/doc)`); + + const playtypes = Object.keys(scorePlaytypeMap) as Playtypes[Game][]; + + // --- 6. Game Stats --- + // This function updates the users "stats" for this game - such as their profile rating or their classes. + const ugsTimeStart = process.hrtime.bigint(); + const classDeltas = await UpdateUsersGameStats(game, playtypes, user.id, classHandler, logger); + + const ugsTime = GetMilisecondsSince(ugsTimeStart); + + logger.debug(`UGS Processing took ${ugsTime} miliseconds.`); + + // --- 7. Goals --- + // Evaluate and update the users goals. This returns information about goals that have changed. + const goalTimeStart = process.hrtime.bigint(); + const goalInfo = await GetAndUpdateUsersGoals(game, user.id, chartIDs, logger); + + const goalTime = GetMilisecondsSince(goalTimeStart); + + logger.debug(`Goal Processing took ${goalTime} miliseconds.`); + + // --- 8. Milestones --- + // Evaluate and update the users milestones. This returns... + const milestoneTimeStart = process.hrtime.bigint(); + const milestoneInfo = await UpdateUsersMilestones(goalInfo, game, playtypes, user.id, logger); + + const milestoneTime = GetMilisecondsSince(milestoneTimeStart); + + logger.debug(`Milestone Processing took ${milestoneTime} miliseconds.`); + + return { + classDeltas, + milestoneInfo, + goalInfo, + playtypes, + scoreIDs, + errors, + sessionInfo, + relativeTimes: { + importParseTimeRel, + pbTimeRel, + sessionTimeRel, + }, + absoluteTimes: { + importParseTime, + sessionTime, + pbTime, + ugsTime, + goalTime, + milestoneTime, + }, + }; +} + /** * Calls UpdateUsersGamePlaytypeStats for every playtype in the import. * @returns A flattened array of ClassDeltas diff --git a/server/src/lib/score-import/framework/score-importing/score-importing.ts b/server/src/lib/score-import/framework/score-importing/score-importing.ts index f06fbee55..99d600d30 100644 --- a/server/src/lib/score-import/framework/score-importing/score-importing.ts +++ b/server/src/lib/score-import/framework/score-importing/score-importing.ts @@ -1,14 +1,20 @@ +import db from "external/mongo/db"; +import { AppendLogCtx, KtLogger } from "lib/logger/logger"; import { ChartDocument, + Game, + IDStrings, ImportProcessingInfo, + ImportTypes, integer, ScoreDocument, SongDocument, - ImportTypes, - IDStrings, } from "tachi-common"; -import { HydrateScore } from "./hydrate-score"; -import { InsertQueue, QueueScoreInsert, ScoreIDs } from "./insert-score"; +import { + ConverterFnReturnOrFailure, + ConverterFnSuccessReturn, + ConverterFunction, +} from "../../import-types/common/types"; import { ConverterFailure, InternalFailure, @@ -16,17 +22,11 @@ import { KTDataNotFoundFailure, SkipScoreFailure, } from "../common/converter-failures"; -import { CreateScoreID } from "./score-id"; -import db from "external/mongo/db"; -import { AppendLogCtx, KtLogger } from "lib/logger/logger"; - -import { - ConverterFnReturnOrFailure, - ConverterFunction, - ConverterFnSuccessReturn, -} from "../../import-types/common/types"; import { DryScore } from "../common/types"; import { OrphanScore } from "../orphans/orphans"; +import { HydrateScore } from "./hydrate-score"; +import { InsertQueue, QueueScoreInsert, ScoreIDs } from "./insert-score"; +import { CreateScoreID } from "./score-id"; /** * Processes the iterable data into the Tachi database. @@ -42,6 +42,7 @@ export async function ImportAllIterableData( iterableData: Iterable | AsyncIterable, ConverterFunction: ConverterFunction, context: C, + game: Game, logger: KtLogger ): Promise { logger.verbose("Getting Blacklist..."); @@ -69,6 +70,7 @@ export async function ImportAllIterableData( data, ConverterFunction, context, + game, blacklist, logger ) @@ -113,6 +115,7 @@ export async function ImportIterableDatapoint( data: D, ConverterFunction: ConverterFunction, context: C, + game: Game, blacklist: string[], logger: KtLogger ): Promise { @@ -139,6 +142,7 @@ export async function ImportIterableDatapoint( cfnReturn.data, cfnReturn.converterContext, cfnReturn.message, + game, logger ); @@ -222,7 +226,8 @@ export async function ProcessSuccessfulConverterReturn( userID: integer, cfnReturn: ConverterFnSuccessReturn, blacklist: string[], - logger: KtLogger + logger: KtLogger, + forceImmediateImport = false ): Promise { const result = await HydrateAndInsertScore( userID, @@ -230,7 +235,8 @@ export async function ProcessSuccessfulConverterReturn( cfnReturn.chart, cfnReturn.song, blacklist, - logger + logger, + forceImmediateImport ); // This used to be a ScoreExists error. However, we never actually care about @@ -258,6 +264,10 @@ export async function ProcessSuccessfulConverterReturn( * @param dryScore - The score that is to be hydrated and inserted. * @param chart - The chart this score is on. * @param song - The song this score is on. + * @param blacklist - A list of ScoreIDs to never write to the database. + * + * @param force - Whether to immediately insert the score into the database + * or not. */ async function HydrateAndInsertScore( userID: integer, @@ -265,7 +275,8 @@ async function HydrateAndInsertScore( chart: ChartDocument, song: SongDocument, blacklist: string[], - importLogger: KtLogger + importLogger: KtLogger, + force = false ): Promise { const scoreID = CreateScoreID(userID, dryScore, chart.chartID); @@ -305,7 +316,12 @@ async function HydrateAndInsertScore( const score = await HydrateScore(userID, dryScore, chart, song, scoreID, logger); - const res = await QueueScoreInsert(score); + let res; + if (force) { + res = await db.scores.insert(score); + } else { + res = await QueueScoreInsert(score); + } // emergency state - this is a last resort for avoiding doubled imports if (res === null) { diff --git a/server/src/lib/score-import/import-types/common/types.ts b/server/src/lib/score-import/import-types/common/types.ts index 32aed2650..5da94cc34 100644 --- a/server/src/lib/score-import/import-types/common/types.ts +++ b/server/src/lib/score-import/import-types/common/types.ts @@ -24,6 +24,7 @@ import { USCClientScore } from "server/router/ir/usc/types"; import { IRUSCContext } from "../ir/usc/types"; import { ClassHandler } from "../../framework/user-game-stats/types"; import { KsHookSV3CScore } from "../ir/kshook-sv3c/types"; + export interface ImportTypeDataMap { "file/eamusement-iidx-csv": IIDXEamusementCSVData; "file/batch-manual": BatchManualScore; @@ -84,6 +85,7 @@ export interface OrphanScoreDocument extend orphanID: string; userID: integer; timeInserted: number; + game: Game; } export interface ConverterFnSuccessReturn { diff --git a/server/src/server/router/api/v1/import/router.test.ts b/server/src/server/router/api/v1/import/router.test.ts index a1cbdd5cd..86581fa91 100644 --- a/server/src/server/router/api/v1/import/router.test.ts +++ b/server/src/server/router/api/v1/import/router.test.ts @@ -359,6 +359,7 @@ t.test("POST /api/v1/import/orphans", async (t) => { identifier: "5.1.1.", difficulty: "ANOTHER", }, + game: "iidx", }, { userID: 1, @@ -379,6 +380,7 @@ t.test("POST /api/v1/import/orphans", async (t) => { identifier: "TITLE NOBODY WILL USE", difficulty: "ANOTHER", }, + game: "iidx", }, ]); diff --git a/server/src/server/router/ir/beatoraja/router.ts b/server/src/server/router/ir/beatoraja/router.ts index 5781d765a..a81cf6f0c 100644 --- a/server/src/server/router/ir/beatoraja/router.ts +++ b/server/src/server/router/ir/beatoraja/router.ts @@ -38,15 +38,22 @@ router.post("/submit-score", RequireNotGuest, async (req, res) => { if (!importRes.body.success) { return res.status(400).json(importRes.body); } else if (importRes.body.body.errors.length !== 0) { - if (importRes.body.body.errors[0].type === "KTDataNotFound") { + const type = importRes.body.body.errors[0].type; + if (type === "KTDataNotFound") { return res.status(202).json({ success: true, description: `Chart and score have been orphaned. This score will reify when atleast ${ServerConfig.BEATORAJA_QUEUE_SIZE} players have played the chart.`, }); + } else if (type === "InternalError") { + return res.status(500).json({ + success: false, + description: `[${importRes.body.body.errors[0].type}] - ${importRes.body.body.errors[0].message}`, + }); } // since we're only ever importing one score, we can guarantee // that this means the score we tried to import was skipped. + return res.status(400).json({ success: false, description: `[${importRes.body.body.errors[0].type}] - ${importRes.body.body.errors[0].message}`, diff --git a/server/src/server/router/ir/usc/router.ts b/server/src/server/router/ir/usc/router.ts index 1b36ccc4e..7c03f6229 100644 --- a/server/src/server/router/ir/usc/router.ts +++ b/server/src/server/router/ir/usc/router.ts @@ -314,7 +314,9 @@ router.post("/scores", RequirePermissions("submit_score"), async (req, res) => { "context.chartHash": chartDoc.data.hashSHA1, }); - await Promise.all(scoresToDeorphan.map((e) => ReprocessOrphan(e, blacklist, logger))); + for (const score of scoresToDeorphan) { + await ReprocessOrphan(score, blacklist, logger); + } } }