@@ -7,6 +7,22 @@ import type { LogLevel } from './types';
77 */
88let sourceRootDirectory : string | undefined ;
99
10+ /**
11+ * Unique session ID for this CDS extractor run to help distinguish
12+ * between multiple concurrent or sequential runs in logs.
13+ */
14+ const sessionId = Math . random ( ) . toString ( 36 ) . substring ( 2 , 8 ) ;
15+
16+ /**
17+ * Start time of the CDS extractor session for performance tracking.
18+ */
19+ const extractorStartTime = Date . now ( ) ;
20+
21+ /**
22+ * Performance tracking state for timing critical operations.
23+ */
24+ const performanceTracking = new Map < string , number > ( ) ;
25+
1026/**
1127 * Sets the source root directory for path filtering in log messages.
1228 * This should typically be called once at the start of the CDS extractor.
@@ -17,9 +33,158 @@ export function setSourceRootDirectory(sourceRoot: string): void {
1733 sourceRootDirectory = sourceRoot ;
1834}
1935
36+ /**
37+ * Calculates elapsed time from start and formats it with appropriate units.
38+ *
39+ * @param startTime - The start timestamp in milliseconds
40+ * @param endTime - The end timestamp in milliseconds (defaults to current time)
41+ * @returns Formatted duration string
42+ */
43+ function formatDuration ( startTime : number , endTime : number = Date . now ( ) ) : string {
44+ const durationMs = endTime - startTime ;
45+
46+ if ( durationMs < 1000 ) {
47+ return `${ durationMs } ;
48+ } else if ( durationMs < 60000 ) {
49+ return `${ ( durationMs / 1000 ) . toFixed ( 2 ) } ;
50+ } else {
51+ const minutes = Math . floor ( durationMs / 60000 ) ;
52+ const seconds = ( ( durationMs % 60000 ) / 1000 ) . toFixed ( 2 ) ;
53+ return `${ minutes } ${ seconds } ;
54+ }
55+ }
56+
57+ /**
58+ * Starts tracking performance for a named operation.
59+ *
60+ * @param operationName - Name of the operation to track
61+ */
62+ export function startPerformanceTracking ( operationName : string ) : void {
63+ performanceTracking . set ( operationName , Date . now ( ) ) ;
64+ cdsExtractorLog ( 'debug' , `Started: ${ operationName } ) ;
65+ }
66+
67+ /**
68+ * Ends tracking performance for a named operation and logs the duration.
69+ *
70+ * @param operationName - Name of the operation to stop tracking
71+ */
72+ export function endPerformanceTracking ( operationName : string ) : void {
73+ const startTime = performanceTracking . get ( operationName ) ;
74+ if ( startTime ) {
75+ const duration = formatDuration ( startTime ) ;
76+ performanceTracking . delete ( operationName ) ;
77+ cdsExtractorLog ( 'info' , `Completed: ${ operationName } ${ duration } ) ;
78+ } else {
79+ cdsExtractorLog ( 'warn' , `No start time found for operation: ${ operationName } ) ;
80+ }
81+ }
82+
83+ /**
84+ * Logs a performance milestone with timing information.
85+ *
86+ * @param milestone - Description of the milestone reached
87+ * @param additionalInfo - Optional additional information to include
88+ */
89+ export function logPerformanceMilestone ( milestone : string , additionalInfo ?: string ) : void {
90+ const currentTime = Date . now ( ) ;
91+ const overallDuration = formatDuration ( extractorStartTime , currentTime ) ;
92+ const info = additionalInfo ? ` - ${ additionalInfo } : '' ;
93+ cdsExtractorLog ( 'info' , `MILESTONE: ${ milestone } ${ overallDuration } ${ info } ) ;
94+ }
95+
96+ /**
97+ * Logs the start of the CDS extractor session with session information.
98+ *
99+ * @param runMode - The run mode being used
100+ * @param sourceRoot - The source root directory being processed
101+ */
102+ export function logExtractorStart ( runMode : string , sourceRoot : string ) : void {
103+ cdsExtractorLog ( 'info' , `=== CDS EXTRACTOR START [${ sessionId } ) ;
104+ cdsExtractorLog ( 'info' , `Run Mode: ${ runMode } ) ;
105+ cdsExtractorLog ( 'info' , `Source Root: ${ sourceRoot } ) ;
106+ }
107+
108+ /**
109+ * Logs the end of the CDS extractor session with final performance summary.
110+ *
111+ * @param success - Whether the extraction completed successfully
112+ * @param additionalSummary - Optional additional summary information
113+ */
114+ export function logExtractorEnd ( success : boolean = true , additionalSummary ?: string ) : void {
115+ const endTime = Date . now ( ) ;
116+ const totalDuration = formatDuration ( extractorStartTime , endTime ) ;
117+ const status = success ? 'SUCCESS' : 'FAILURE' ;
118+
119+ if ( additionalSummary ) {
120+ cdsExtractorLog ( 'info' , additionalSummary ) ;
121+ }
122+
123+ cdsExtractorLog ( 'info' , `=== CDS EXTRACTOR END [${ sessionId } ${ status } ) ;
124+ cdsExtractorLog ( 'info' , `Total Duration: ${ totalDuration } ) ;
125+ }
126+
127+ /**
128+ * Logs current memory usage for performance debugging.
129+ *
130+ * @param context - Context description for the memory check
131+ */
132+ export function logMemoryUsage ( context : string ) : void {
133+ if ( typeof process !== 'undefined' && process . memoryUsage ) {
134+ try {
135+ const memUsage = process . memoryUsage ( ) ;
136+ const formatBytes = ( bytes : number ) : string => {
137+ if ( bytes === 0 ) return '0 B' ;
138+ const k = 1024 ;
139+ const sizes = [ 'B' , 'KB' , 'MB' , 'GB' ] ;
140+ const i = Math . floor ( Math . log ( bytes ) / Math . log ( k ) ) ;
141+ return `${ parseFloat ( ( bytes / Math . pow ( k , i ) ) . toFixed ( 2 ) ) } ${ sizes [ i ] } ;
142+ } ;
143+
144+ cdsExtractorLog (
145+ 'debug' ,
146+ `Memory usage - ${ context } ${ formatBytes ( memUsage . rss ) } ${ formatBytes ( memUsage . heapUsed ) } ${ formatBytes ( memUsage . heapTotal ) } ${ formatBytes ( memUsage . external ) } ,
147+ ) ;
148+ } catch {
149+ // Silently ignore errors when memory usage is not available
150+ // This ensures the function never throws and doesn't interrupt the extraction process
151+ }
152+ }
153+ }
154+
155+ /**
156+ * Logs a performance counter with current count and rate information.
157+ *
158+ * @param counterName - Name of the counter
159+ * @param currentCount - Current count value
160+ * @param startTime - Start time for rate calculation (optional)
161+ * @param totalExpected - Total expected count for progress percentage (optional)
162+ */
163+ export function logPerformanceCounter (
164+ counterName : string ,
165+ currentCount : number ,
166+ startTime ?: number ,
167+ totalExpected ?: number ,
168+ ) : void {
169+ let message = `${ counterName } ${ currentCount } ;
170+
171+ if ( totalExpected && totalExpected > 0 ) {
172+ const percentage = ( ( currentCount / totalExpected ) * 100 ) . toFixed ( 1 ) ;
173+ message += ` / ${ totalExpected } ${ percentage } ;
174+ }
175+
176+ if ( startTime ) {
177+ const elapsed = Date . now ( ) - startTime ;
178+ const rate = elapsed > 0 ? ( ( currentCount / elapsed ) * 1000 ) . toFixed ( 1 ) : '0' ;
179+ message += ` - Rate: ${ rate } ;
180+ }
181+
182+ cdsExtractorLog ( 'debug' , message ) ;
183+ }
184+
20185/**
21186 * Unified logging function for the CDS extractor. Provides consistent
22- * log formatting with level prefixes and path filtering.
187+ * log formatting with level prefixes, elapsed time, session IDs, and path filtering.
23188 *
24189 * @param level - The log level ('debug', 'info', 'warn', 'error')
25190 * @param message - The primary message or data to log
@@ -34,8 +199,9 @@ export function cdsExtractorLog(
34199 throw new Error ( 'Source root directory is not set. Call setSourceRootDirectory() first.' ) ;
35200 }
36201
37- // Convert log level to uppercase for consistent formatting
38- const levelPrefix = `${ level . toUpperCase ( ) } ;
202+ const currentTime = Date . now ( ) ;
203+ const elapsedMs = currentTime - extractorStartTime ;
204+ const levelPrefix = `[CDS-${ sessionId } ${ elapsedMs } ${ level . toUpperCase ( ) } ;
39205
40206 // Process the primary message for path filtering if it's a string
41207 let processedMessage : string ;
0 commit comments