diff --git a/src/routes/getSkipSegments.ts b/src/routes/getSkipSegments.ts index a9500f8..d915f0e 100644 --- a/src/routes/getSkipSegments.ts +++ b/src/routes/getSkipSegments.ts @@ -13,7 +13,7 @@ import { getReputation } from "../utils/reputation"; import { getService } from "../utils/getService"; -async function prepareCategorySegments(req: Request, videoID: VideoID, service: Service, segments: DBSegment[], cache: SegmentCache = { shadowHiddenSegmentIPs: {} }, useCache: boolean): Promise { +async function prepareCategorySegments(req: Request, videoID: VideoID, service: Service, segments: DBSegment[], cache: SegmentCache = { shadowHiddenSegmentIPs: {} }, useCache: boolean, logData: any): Promise { const shouldFilter: boolean[] = await Promise.all(segments.map(async (segment) => { if (segment.votes < -1 && !segment.required) { return false; //too untrustworthy, just ignore it @@ -47,9 +47,19 @@ async function prepareCategorySegments(req: Request, videoID: VideoID, service: return shouldShadowHide; })); + if (logData.extraLogging) { + Logger.error(`Preparing segments: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + const filteredSegments = segments.filter((_, index) => shouldFilter[index]); - return (await chooseSegments(videoID, service, filteredSegments, useCache)).map((chosenSegment) => ({ + if (logData.extraLogging) { + Logger.error(`Filter complete: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + + return (await chooseSegments(videoID, service, filteredSegments, useCache, logData)).map((chosenSegment) => ({ category: chosenSegment.category, actionType: chosenSegment.actionType, segment: [chosenSegment.startTime, chosenSegment.endTime], @@ -83,7 +93,7 @@ async function getSegmentsByVideoID(req: Request, videoID: VideoID, categories: }, {}); const canUseCache = requiredSegments.length === 0; - let processedSegments: Segment[] = (await prepareCategorySegments(req, videoID, service, segments, cache, canUseCache)) + let processedSegments: Segment[] = (await prepareCategorySegments(req, videoID, service, segments, cache, canUseCache, {})) .filter((segment: Segment) => categories.includes(segment?.category) && (actionTypes.includes(segment?.actionType))); if (forcePoiAsSkip) { @@ -113,12 +123,23 @@ async function getSegmentsByHash(req: Request, hashedVideoIDPrefix: VideoIDHash, actionTypes.push(ActionType.Poi); } + const logData = { + extraLogging: req.params.extraLogging, + startTime: Date.now(), + lastTime: Date.now() + }; + try { type SegmentWithHashPerVideoID = SBRecord; categories = categories.filter((category) => !(/[^a-z|_|-]/.test(category))); if (categories.length === 0) return null; + if (logData.extraLogging) { + Logger.error(`About to fetch: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + const segmentPerVideoID: SegmentWithHashPerVideoID = (await getSegmentsFromDBByHash(hashedVideoIDPrefix, service)) .reduce((acc: SegmentWithHashPerVideoID, segment: DBSegment) => { acc[segment.videoID] = acc[segment.videoID] || { @@ -133,6 +154,11 @@ async function getSegmentsByHash(req: Request, hashedVideoIDPrefix: VideoIDHash, return acc; }, {}); + if (logData.extraLogging) { + Logger.error(`Fetch complete: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + for (const [videoID, videoData] of Object.entries(segmentPerVideoID)) { const data: VideoData = { hash: videoData.hash, @@ -140,7 +166,7 @@ async function getSegmentsByHash(req: Request, hashedVideoIDPrefix: VideoIDHash, }; const canUseCache = requiredSegments.length === 0; - data.segments = (await prepareCategorySegments(req, videoID as VideoID, service, videoData.segments, cache, canUseCache)) + data.segments = (await prepareCategorySegments(req, videoID as VideoID, service, videoData.segments, cache, canUseCache, logData)) .filter((segment: Segment) => categories.includes(segment?.category) && actionTypes.includes(segment?.actionType)); if (forcePoiAsSkip) { @@ -153,6 +179,11 @@ async function getSegmentsByHash(req: Request, hashedVideoIDPrefix: VideoIDHash, if (data.segments.length > 0) { segments[videoID] = data; } + + if (logData.extraLogging) { + Logger.error(`Done one video: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } } return segments; @@ -255,13 +286,18 @@ function getWeightedRandomChoice(choices: T[], amountOf return chosen; } -async function chooseSegments(videoID: VideoID, service: Service, segments: DBSegment[], useCache: boolean): Promise { +async function chooseSegments(videoID: VideoID, service: Service, segments: DBSegment[], useCache: boolean, logData: any): Promise { const fetchData = async () => await buildSegmentGroups(segments); const groups = useCache ? await QueryCacher.get(fetchData, skipSegmentGroupsKey(videoID, service)) : await fetchData(); + if (logData.extraLogging) { + Logger.error(`Built groups: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + // Filter for only 1 item for POI categories and Full video let chosenGroups = getWeightedRandomChoice(groups, 1, true, (choice) => choice.segments[0].actionType === ActionType.Full); chosenGroups = getWeightedRandomChoice(chosenGroups, 1, true, (choice) => choice.segments[0].actionType === ActionType.Poi); diff --git a/src/routes/voteOnSponsorTime.ts b/src/routes/voteOnSponsorTime.ts index b51d968..8d13976 100644 --- a/src/routes/voteOnSponsorTime.ts +++ b/src/routes/voteOnSponsorTime.ts @@ -310,7 +310,18 @@ export async function voteOnSponsorTime(req: Request, res: Response): Promise { +export async function vote(ip: IPAddress, UUID: SegmentUUID, paramUserID: UserID, type: number, category?: Category, logData = {} as any): Promise<{ status: number, message?: string, json?: unknown }> { // missing key parameters if (!UUID || !paramUserID || !(type !== undefined || category)) { return { status: 400 }; @@ -354,6 +365,11 @@ export async function vote(ip: IPAddress, UUID: SegmentUUID, paramUserID: UserID return { status: 404 }; } + if (logData.extraLogging) { + Logger.error(`Got segment info: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + const isTempVIP = await isUserTempVIP(nonAnonUserID, segmentInfo.videoID); const isVIP = await isUserVIP(nonAnonUserID); @@ -415,10 +431,20 @@ export async function vote(ip: IPAddress, UUID: SegmentUUID, paramUserID: UserID checkVideoDuration(UUID); } + if (logData.extraLogging) { + Logger.error(`Main prep done: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + try { // check if vote has already happened const votesRow = await privateDB.prepare("get", `SELECT "type" FROM "votes" WHERE "userID" = ? AND "UUID" = ?`, [userID, UUID]); + if (logData.extraLogging) { + Logger.error(`Got previous vote info: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + // -1 for downvote, 1 for upvote. Maybe more depending on reputation in the future // oldIncrementAmount will be zero if row is null let incrementAmount = 0; @@ -480,6 +506,11 @@ export async function vote(ip: IPAddress, UUID: SegmentUUID, paramUserID: UserID const ableToVote = isVIP || isTempVIP || userAbleToVote; + if (logData.extraLogging) { + Logger.error(`About to run vote code ${ableToVote}: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + if (ableToVote) { //update the votes table if (votesRow) { @@ -507,8 +538,19 @@ export async function vote(ip: IPAddress, UUID: SegmentUUID, paramUserID: UserID await db.prepare("run", 'UPDATE "sponsorTimes" SET "locked" = 0 WHERE "UUID" = ?', [UUID]); } + if (logData.extraLogging) { + Logger.error(`Did vote stuff: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + QueryCacher.clearSegmentCache(segmentInfo); } + + if (logData.extraLogging) { + Logger.error(`Ready to send webhook ${incrementAmount - oldIncrementAmount !== 0}: ${Date.now() - logData.lastTime}, ${Date.now() - logData.startTime}`); + logData.lastTime = Date.now(); + } + if (incrementAmount - oldIncrementAmount !== 0) { sendWebhooks({ UUID,