[FEATURE] Implement Log Level Differentiation to Reduce Verbosity and Improve Filtering

[gmij]

Description:
The current logging system outputs all events at the DEBUG level (as shown in the attached screenshot), leading to two main issues:

​Excessive log volume - High-frequency debug entries (e.g., 5+ entries within 1 millisecond) cause rapid log growth
​Poor log filtering - Critical events are buried in debug noise, making troubleshooting inefficient
Proposed Solution:
Implement log level differentiation following standard practices:

Use ​INFO level for:
• Service call initialization/entry points
• Service call completion/exit points
Reserve ​DEBUG level for:
• Detailed process tracing
• Internal state changes (e.g., cache operations shown in logs)
• Memory entry operations
Benefits:

Reduce log volume by 40-60% in normal operation (INFO level default)
Enable targeted debugging with level filtering
Improve operational visibility for key lifecycle events
Additional Context:
Attached logs show repeated DEBUG entries from the Fusion Cache component (memory operations, cache connectivity checks, and GetOrSet operations) that would be better classified as DEBUG, while missing higher-level INFO entries for service boundaries.

[jodydonetti]

Hi @gmij , missing attachments.

[gmij]

for example, the key match __fc:t:* , continue with debug. other with log level info

@jodydonetti

[gmij]

now... on log viewr, enable filter with K=__fc:t:* and K=__fc:t:! not show.
@jodydonetti

[jodydonetti]

Hi @gmij , traveling right now, will answer as soon as I can.
Thanks for sharing!

[gmij]

Ok...
Ps.
the Log Message Template is to long... the Cache Name, InstanceId, Cache Life Time ... Can Use Log Scope to record Log .
For Example :
log.BeginScope("{InstanceId}.....", InstanceId){
logger.xxx
}

[jodydonetti]

Hi @gmij I'm back on this.

Description: The current logging system outputs all events at the DEBUG level

All "main" events, yes. Some others more low level are at the TRACE level.

Proposed Solution: Implement log level differentiation following standard practices:

Use ​INFO level for:

• Service call initialization/entry points
• Service call completion/exit points
  Reserve ​DEBUG level for:
• Detailed process tracing
• Internal state changes (e.g., cache operations shown in logs)
• Memory entry operations

I've been thinking about this change from some time now, by also including TRACE level.

Let's use the last example here, where with min level TRACE we would have (simplified):

INFO: calling GetOrSetAsync<T>
TRACE: [MC] trying to get from memory
DEBUG: [MC] memory entry not found
TRACE: waiting to acquire the LOCK
TRACE: LOCK acquired
TRACE: [MC] trying to get from memory
DEBUG: [MC] memory entry not found
TRACE: [DC] trying to get entry from distributed
DEBUG: [DC] distributed entry not found
DEBUG: calling the factory (timeout=/)
DEBUG: [MC] saving memory entry
TRACE: releasing MEMORY LOCK
TRACE: MEMORY LOCK released
DEBUG: [DC] saving distributed entry
TRACE: [DC] serializing the entry
TRACE: [DC] before setting entry in distributed
TRACE: [DC] after setting entry in distributed
DEBUG: [BP] publishing set
TRACE: [BP] before sending a backplane notification (background)
TRACE: [BP] after sending a backplane notification (background)
INFO: return from GetOrSetAsync<T>

By setting min level to DEBUG we would have instead:

INFO: calling GetOrSetAsync<T>
DEBUG: [MC] memory entry not found
DEBUG: [MC] memory entry not found
DEBUG: [DC] distributed entry not found
DEBUG: calling the factory (timeout=/)
DEBUG: [MC] saving memory entry
DEBUG: [DC] saving distributed entry
DEBUG: [BP] publishing set
INFO: return from GetOrSetAsync<T>

And finally, by setting min level to INFO we would have:

INFO: calling GetOrSetAsync<T>
INFO: return from GetOrSetAsync<T>

Thoughts?

the Log Message Template is to long...
[...]Can Use Log Scope to record Log .

I feel the same, BUT: I did that because I haven't found a way so that the default experience of logging to a file/console would give enough informations in a quickly readable way so that debugging would still be easy or, at least, doable. If I remember correctly, by default scope variables is not included in the log output, so it became way less usable without them directly exposed.

[gmij]

the log level is ok.

the log message template, can try serilog , write to Console and Seq,
the Console template can print scope variables.

Add {Properties:j} to the output template to include additional context information.

https://stackoverflow.com/questions/66360594/how-do-i-include-scope-with-serilogs-console-sink-when-using-microsofts-ilogge

https://github.com/serilog/serilog/wiki/Configuration-Basics#output-templates