perf: add timing metrics and reduce excessive logging

- Add duration tracking for fetchProfiles (shows how long it takes)
- Add total time tracking for entire resolution process
- Reduce log noise by only logging when profileLabels size changes
- Helps identify performance bottlenecks
This commit is contained in:
Gigi
2025-11-02 20:54:40 +01:00
parent 8a431d962e
commit 3136b198d5
2 changed files with 24 additions and 9 deletions

View File

@@ -1,4 +1,4 @@
import React, { useState, useEffect, useRef } from 'react'
import React, { useState, useEffect, useRef, useMemo } from 'react'
import { RelayPool } from 'applesauce-relay'
import { extractNaddrUris, replaceNostrUrisInMarkdownWithProfileLabels } from '../utils/nostrUriResolver'
import { fetchArticleTitles } from '../services/articleTitleResolver'
@@ -28,11 +28,13 @@ export const useMarkdownToHTML = (
const [processedMarkdown, setProcessedMarkdown] = useState<string>('')
const [articleTitles, setArticleTitles] = useState<Map<string, string>>(new Map())
console.log(`[${ts()}] [npub-resolve] useMarkdownToHTML: markdown length:`, markdown?.length || 0, 'hasRelayPool:', !!relayPool)
// Resolve profile labels progressively as profiles load
const profileLabels = useProfileLabels(markdown || '', relayPool)
console.log(`[${ts()}] [npub-resolve] useMarkdownToHTML: Profile labels size:`, profileLabels.size)
// Log when markdown or profile labels change (but throttle excessive logs)
useEffect(() => {
console.log(`[${ts()}] [npub-resolve] useMarkdownToHTML: markdown length:`, markdown?.length || 0, 'hasRelayPool:', !!relayPool, 'Profile labels size:', profileLabels.size)
}, [markdown?.length, profileLabels.size, relayPool])
// Fetch article titles
useEffect(() => {

View File

@@ -1,4 +1,4 @@
import { useMemo, useState, useEffect } from 'react'
import { useMemo, useState, useEffect, useRef } from 'react'
import { Hooks } from 'applesauce-react'
import { Helpers, IEventStore } from 'applesauce-core'
import { getContentPointers } from 'applesauce-factory/helpers'
@@ -50,9 +50,11 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
}, [content])
const [profileLabels, setProfileLabels] = useState<Map<string, string>>(new Map())
const lastLoggedSize = useRef<number>(0)
// Build initial labels from eventStore, then fetch missing profiles
useEffect(() => {
const startTime = Date.now()
console.log(`[${ts()}] [npub-resolve] Building labels, profileData:`, profileData.length, 'hasEventStore:', !!eventStore)
// First, get profiles from eventStore synchronously
@@ -88,10 +90,12 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
// Fetch missing profiles asynchronously
if (pubkeysToFetch.length > 0 && relayPool && eventStore) {
const fetchStartTime = Date.now()
console.log(`[${ts()}] [npub-resolve] Fetching`, pubkeysToFetch.length, 'missing profiles')
fetchProfiles(relayPool, eventStore as unknown as IEventStore, pubkeysToFetch)
.then((fetchedProfiles) => {
console.log(`[${ts()}] [npub-resolve] fetchProfiles returned`, fetchedProfiles.length, 'profiles')
const fetchDuration = Date.now() - fetchStartTime
console.log(`[${ts()}] [npub-resolve] fetchProfiles returned`, fetchedProfiles.length, 'profiles in', fetchDuration, 'ms')
// First, use the profiles returned from fetchProfiles directly
const updatedLabels = new Map(labels)
@@ -153,16 +157,25 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
}
})
console.log(`[${ts()}] [npub-resolve] After fetch - resolved:`, updatedLabels.size, 'total | from array:', resolvedFromArray, '| from store:', resolvedFromStore, '| with names:', withNames, '| without names:', withoutNames, '| missing:', missingFromStore, '| out of', profileData.length)
const totalDuration = Date.now() - startTime
console.log(`[${ts()}] [npub-resolve] After fetch - resolved:`, updatedLabels.size, 'total | from array:', resolvedFromArray, '| from store:', resolvedFromStore, '| with names:', withNames, '| without names:', withoutNames, '| missing:', missingFromStore, '| out of', profileData.length, '| total time:', totalDuration, 'ms')
setProfileLabels(updatedLabels)
})
.catch(err => {
console.error(`[${ts()}] [npub-resolve] Error fetching profiles:`, err)
const fetchDuration = Date.now() - fetchStartTime
console.error(`[${ts()}] [npub-resolve] Error fetching profiles after`, fetchDuration, 'ms:', err)
})
}
}, [profileData, eventStore, relayPool])
// Only log when size actually changes to reduce noise
useEffect(() => {
if (profileLabels.size !== lastLoggedSize.current) {
console.log(`[${ts()}] [npub-resolve] Final labels map size:`, profileLabels.size)
lastLoggedSize.current = profileLabels.size
}
}, [profileLabels.size])
return profileLabels
}