debug: add timestamps to all npub-resolve logs for performance analysis

- Add timestamp helper function (HH:mm:ss.SSS format)
- Update all console.log/error statements to include timestamps
- Helps identify timing bottlenecks in profile resolution
This commit is contained in:
Gigi
2025-11-02 20:53:22 +01:00
parent 50ab59ebcd
commit 8a431d962e
4 changed files with 61 additions and 33 deletions

View File

@@ -2,6 +2,13 @@ import React from 'react'
import NostrMentionLink from './NostrMentionLink'
import { Tokens } from 'applesauce-content/helpers'
// Helper to add timestamps to logs
const ts = () => {
const now = new Date()
const ms = now.getMilliseconds().toString().padStart(3, '0')
return `${now.toLocaleTimeString('en-US', { hour12: false })}.${ms}`
}
interface RichContentProps {
content: string
className?: string
@@ -19,7 +26,7 @@ const RichContent: React.FC<RichContentProps> = ({
content,
className = 'bookmark-content'
}) => {
console.log('[npub-resolve] RichContent: Rendering, content length:', content?.length || 0)
console.log(`[${ts()}] [npub-resolve] RichContent: Rendering, content length:`, content?.length || 0)
try {
// Pattern to match:
@@ -30,7 +37,7 @@ const RichContent: React.FC<RichContentProps> = ({
const combinedPattern = new RegExp(`(${nostrPattern.source}|${urlPattern.source})`, 'gi')
const parts = content.split(combinedPattern)
console.log('[npub-resolve] RichContent: Split into parts:', parts.length)
console.log(`[${ts()}] [npub-resolve] RichContent: Split into parts:`, parts.length)
// Helper to check if a string is a nostr identifier (without mutating regex state)
const isNostrIdentifier = (str: string): boolean => {
@@ -82,7 +89,7 @@ const RichContent: React.FC<RichContentProps> = ({
</div>
)
} catch (err) {
console.error('[npub-resolve] RichContent: Error rendering:', err)
console.error(`[${ts()}] [npub-resolve] RichContent: Error rendering:`, err)
return <div className={className}>Error rendering content</div>
}
}

View File

@@ -4,6 +4,13 @@ import { extractNaddrUris, replaceNostrUrisInMarkdownWithProfileLabels } from '.
import { fetchArticleTitles } from '../services/articleTitleResolver'
import { useProfileLabels } from './useProfileLabels'
// Helper to add timestamps to logs
const ts = () => {
const now = new Date()
const ms = now.getMilliseconds().toString().padStart(3, '0')
return `${now.toLocaleTimeString('en-US', { hour12: false })}.${ms}`
}
/**
* Hook to convert markdown to HTML using a hidden ReactMarkdown component
* Also processes nostr: URIs in the markdown and resolves article titles
@@ -21,11 +28,11 @@ export const useMarkdownToHTML = (
const [processedMarkdown, setProcessedMarkdown] = useState<string>('')
const [articleTitles, setArticleTitles] = useState<Map<string, string>>(new Map())
console.log('[npub-resolve] useMarkdownToHTML: markdown length:', markdown?.length || 0, 'hasRelayPool:', !!relayPool)
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('[npub-resolve] useMarkdownToHTML: Profile labels size:', profileLabels.size)
console.log(`[${ts()}] [npub-resolve] useMarkdownToHTML: Profile labels size:`, profileLabels.size)
// Fetch article titles
useEffect(() => {
@@ -71,8 +78,8 @@ export const useMarkdownToHTML = (
let isCancelled = false
const processMarkdown = () => {
console.log('[npub-resolve] useMarkdownToHTML: Processing markdown, length:', markdown.length)
console.log('[npub-resolve] useMarkdownToHTML: Profile labels:', profileLabels.size, 'Article titles:', articleTitles.size)
console.log(`[${ts()}] [npub-resolve] useMarkdownToHTML: Processing markdown, length:`, markdown.length)
console.log(`[${ts()}] [npub-resolve] useMarkdownToHTML: Profile labels:`, profileLabels.size, 'Article titles:', articleTitles.size)
try {
// Replace nostr URIs with profile labels (progressive) and article titles
const processed = replaceNostrUrisInMarkdownWithProfileLabels(
@@ -80,13 +87,13 @@ export const useMarkdownToHTML = (
profileLabels,
articleTitles
)
console.log('[npub-resolve] useMarkdownToHTML: Processed markdown length:', processed.length)
console.log(`[${ts()}] [npub-resolve] useMarkdownToHTML: Processed markdown length:`, processed.length)
if (isCancelled) return
setProcessedMarkdown(processed)
} catch (err) {
console.error('[npub-resolve] useMarkdownToHTML: Error processing markdown:', err)
console.error(`[${ts()}] [npub-resolve] useMarkdownToHTML: Error processing markdown:`, err)
if (!isCancelled) {
setProcessedMarkdown(markdown) // Fallback to original
}

View File

@@ -7,6 +7,13 @@ import { fetchProfiles } from '../services/profileService'
const { getPubkeyFromDecodeResult, encodeDecodeResult } = Helpers
// Helper to add timestamps to logs
const ts = () => {
const now = new Date()
const ms = now.getMilliseconds().toString().padStart(3, '0')
return `${now.toLocaleTimeString('en-US', { hour12: false })}.${ms}`
}
/**
* Hook to resolve profile labels from content containing npub/nprofile identifiers
* Returns a Map of encoded identifier -> display name that updates progressively as profiles load
@@ -16,12 +23,12 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
// Extract profile pointers (npub and nprofile) using applesauce helpers
const profileData = useMemo(() => {
console.log('[npub-resolve] Processing content, length:', content?.length || 0)
console.log(`[${ts()}] [npub-resolve] Processing content, length:`, content?.length || 0)
try {
const pointers = getContentPointers(content)
console.log('[npub-resolve] Found pointers:', pointers.length, 'types:', pointers.map(p => p.type))
console.log(`[${ts()}] [npub-resolve] Found pointers:`, pointers.length, 'types:', pointers.map(p => p.type))
const filtered = pointers.filter(p => p.type === 'npub' || p.type === 'nprofile')
console.log('[npub-resolve] Profile pointers:', filtered.length)
console.log(`[${ts()}] [npub-resolve] Profile pointers:`, filtered.length)
const result: Array<{ pubkey: string; encoded: string }> = []
filtered.forEach(pointer => {
try {
@@ -31,13 +38,13 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
result.push({ pubkey, encoded: encoded as string })
}
} catch (err) {
console.error('[npub-resolve] Error processing pointer:', err, pointer)
console.error(`[${ts()}] [npub-resolve] Error processing pointer:`, err, pointer)
}
})
console.log('[npub-resolve] Profile data after filtering:', result.length)
console.log(`[${ts()}] [npub-resolve] Profile data after filtering:`, result.length)
return result
} catch (err) {
console.error('[npub-resolve] Error extracting pointers:', err)
console.error(`[${ts()}] [npub-resolve] Error extracting pointers:`, err)
return []
}
}, [content])
@@ -46,7 +53,7 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
// Build initial labels from eventStore, then fetch missing profiles
useEffect(() => {
console.log('[npub-resolve] Building labels, profileData:', profileData.length, 'hasEventStore:', !!eventStore)
console.log(`[${ts()}] [npub-resolve] Building labels, profileData:`, profileData.length, 'hasEventStore:', !!eventStore)
// First, get profiles from eventStore synchronously
const labels = new Map<string, string>()
@@ -61,7 +68,7 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
const displayName = profileData.display_name || profileData.name || profileData.nip05
if (displayName) {
labels.set(encoded, `@${displayName}`)
console.log('[npub-resolve] Found in eventStore:', encoded, '->', displayName)
console.log(`[${ts()}] [npub-resolve] Found in eventStore:`, encoded, '->', displayName)
} else {
pubkeysToFetch.push(pubkey)
}
@@ -81,10 +88,10 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
// Fetch missing profiles asynchronously
if (pubkeysToFetch.length > 0 && relayPool && eventStore) {
console.log('[npub-resolve] Fetching', pubkeysToFetch.length, 'missing profiles')
console.log(`[${ts()}] [npub-resolve] Fetching`, pubkeysToFetch.length, 'missing profiles')
fetchProfiles(relayPool, eventStore as unknown as IEventStore, pubkeysToFetch)
.then((fetchedProfiles) => {
console.log('[npub-resolve] fetchProfiles returned', fetchedProfiles.length, 'profiles')
console.log(`[${ts()}] [npub-resolve] fetchProfiles returned`, fetchedProfiles.length, 'profiles')
// First, use the profiles returned from fetchProfiles directly
const updatedLabels = new Map(labels)
@@ -108,15 +115,15 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
if (displayName) {
updatedLabels.set(encoded, `@${displayName}`)
withNames++
console.log('[npub-resolve] Resolved from fetched array:', encoded.slice(0, 30) + '...', '->', displayName)
console.log(`[${ts()}] [npub-resolve] Resolved from fetched array:`, encoded.slice(0, 30) + '...', '->', displayName)
} else {
withoutNames++
if (withoutNames <= 3) {
console.log('[npub-resolve] Fetched profile has no name/display_name/nip05:', encoded.slice(0, 30) + '...', 'content keys:', Object.keys(profileData))
console.log(`[${ts()}] [npub-resolve] Fetched profile has no name/display_name/nip05:`, encoded.slice(0, 30) + '...', 'content keys:', Object.keys(profileData))
}
}
} catch (err) {
console.error('[npub-resolve] Error parsing fetched profile for', encoded.slice(0, 30) + '...', err)
console.error(`[${ts()}] [npub-resolve] Error parsing fetched profile for`, encoded.slice(0, 30) + '...', err)
}
} else if (eventStore) {
// Fallback: check eventStore (in case fetchProfiles stored but didn't return)
@@ -129,15 +136,15 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
if (displayName) {
updatedLabels.set(encoded, `@${displayName}`)
withNames++
console.log('[npub-resolve] Resolved from eventStore:', encoded.slice(0, 30) + '...', '->', displayName)
console.log(`[${ts()}] [npub-resolve] Resolved from eventStore:`, encoded.slice(0, 30) + '...', '->', displayName)
}
} catch (err) {
console.error('[npub-resolve] Error parsing profile event for', encoded.slice(0, 30) + '...', err)
console.error(`[${ts()}] [npub-resolve] Error parsing profile event for`, encoded.slice(0, 30) + '...', err)
}
} else {
missingFromStore++
if (missingFromStore <= 3) {
console.log('[npub-resolve] Profile not found in array or eventStore:', pubkey.slice(0, 16) + '...')
console.log(`[${ts()}] [npub-resolve] Profile not found in array or eventStore:`, pubkey.slice(0, 16) + '...')
}
}
} else {
@@ -146,16 +153,16 @@ export function useProfileLabels(content: string, relayPool?: RelayPool | null):
}
})
console.log('[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)
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)
setProfileLabels(updatedLabels)
})
.catch(err => {
console.error('[npub-resolve] Error fetching profiles:', err)
console.error(`[${ts()}] [npub-resolve] Error fetching profiles:`, err)
})
}
}, [profileData, eventStore, relayPool])
console.log('[npub-resolve] Final labels map size:', profileLabels.size)
console.log(`[${ts()}] [npub-resolve] Final labels map size:`, profileLabels.size)
return profileLabels
}

View File

@@ -4,6 +4,13 @@ import { Tokens } from 'applesauce-content/helpers'
import { getContentPointers } from 'applesauce-factory/helpers'
import { encodeDecodeResult } from 'applesauce-core/helpers'
// Helper to add timestamps to logs
const ts = () => {
const now = new Date()
const ms = now.getMilliseconds().toString().padStart(3, '0')
return `${now.toLocaleTimeString('en-US', { hour12: false })}.${ms}`
}
/**
* Regular expression to match nostr: URIs and bare NIP-19 identifiers
* Uses applesauce Tokens.nostrLink which includes word boundary checks
@@ -16,10 +23,10 @@ const NOSTR_URI_REGEX = Tokens.nostrLink
* Extract all nostr URIs from text using applesauce helpers
*/
export function extractNostrUris(text: string): string[] {
console.log('[npub-resolve] extractNostrUris: text length:', text?.length || 0)
console.log(`[${ts()}] [npub-resolve] extractNostrUris: text length:`, text?.length || 0)
try {
const pointers = getContentPointers(text)
console.log('[npub-resolve] extractNostrUris: Found pointers:', pointers.length)
console.log(`[${ts()}] [npub-resolve] extractNostrUris: Found pointers:`, pointers.length)
const result: string[] = []
pointers.forEach(pointer => {
try {
@@ -28,13 +35,13 @@ export function extractNostrUris(text: string): string[] {
result.push(encoded)
}
} catch (err) {
console.error('[npub-resolve] extractNostrUris: Error encoding pointer:', err, pointer)
console.error(`[${ts()}] [npub-resolve] extractNostrUris: Error encoding pointer:`, err, pointer)
}
})
console.log('[npub-resolve] extractNostrUris: Extracted URIs:', result.length)
console.log(`[${ts()}] [npub-resolve] extractNostrUris: Extracted URIs:`, result.length)
return result
} catch (err) {
console.error('[npub-resolve] extractNostrUris: Error:', err)
console.error(`[${ts()}] [npub-resolve] extractNostrUris: Error:`, err)
return []
}
}