chore: Add automatically the filename : line_nu in log messages, and do some cleaning

[ido777]

Summary

the main change is api/config/winston.js

1. Automatically add to log messages the file name and the line number of the logger source code.
2. File name and line nu are formatted so that VS Code Terminal will detect it and make it clickable, to ease getting to the relevant source code line from the log.
   Example:

2024-04-15 11:13:36 info: [./api/server/index.js:99] Server listening at http://localhost:3080

[./api/server/index.js:99] is created automatically and when you click on it in VS Code on this part it will bring you to the line in the code that produced the message

Other less important changes:

3. FIX BUG: changed in /api/app/clients/PluginsClient.js from logger.debug('sendMessage', { message, opts }); -> logger.debug('sendMessage', { HumanMessage, opts });
   since the message argument name is part of the logger system and causes this log instance to malfunction.
   in other words: Don't call logger.debug with message as one of the parameters

There might be more places where this is applicable,

4. Most of the changes are removing the explicit filename from the logger.debug commands since it is now generated automatically and is not needed anymore.

Change Type

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)

Testing

Mainly manual work, and fixing a test that failed.

Test Configuration:

Checklist

Please delete any irrelevant options.

• My code adheres to this project's style guidelines
• I have performed a self-review of my own code
• I have commented in any complex areas of my code
• My changes do not introduce new warnings
• Local unit tests pass with my changes

[danny-avila]

I'd rather not complicate the logging with even more logic. It can really hurt performance as the logger is called frequently, and regex processing can be heavy.

I'll keep this in mind to patch:

FIX BUG: changed in /api/app/clients/PluginsClient.js from logger.debug('sendMessage', { message, opts }); -> logger.debug('sendMessage', { HumanMessage, opts });
since the message argument name is part of the logger system and causes this log instance to malfunction.
in other words: Don't call logger.debug with message as one of the parameters

[ido777]

@danny-avila
I understand your concerns regarding the potential performance impact of adding automatic filename and line number logging. However, I believe the benefits of this feature could significantly outweigh the concerns for several reasons

1. Developer Efficiency: Automatically adding file names and line numbers to logs enhances developer productivity and debugging efficiency. By making log statements clickable in environments like VS Code, developers can quickly navigate to the source of an issue, reducing the time spent on tracing log origins manually.

2. Maintainability: With this feature, the need to manually update log statements with file names and line numbers is eliminated. This reduces human error and ensures that logs are always accurate, even as the codebase evolves and files are refactored or moved.

3. Performance Considerations: While it's valid that adding regex processing could introduce some overhead, the impact might be less significant than anticipated. We can mitigate performance concerns by:

• Changing it to work only on DEBUG messages and not INFO
• Remind users that production environments where performance is critical should not have DEBUG logging on.
• Later in the project, if we find it to be a problem we can implement a lightweight method to capture filenames and line numbers, possibly using native JavaScript capabilities instead of regex.

As Kent Beck says “Make it work. Make it right. Make it fast”, Developer Efficiency and Maintainability should be handed sonner in the project lifecycle then Performance ...

[ido777]

One more comment, I wasted a lot of time on the bug I fixed, and I found it really annoying to work with logs and debug the application, add to this that there is no good developer documentation so understanding the root cause of something currently is not simple. So this PR was not a nice idea I added to the code, but a remedy for a pain I had while working with the project code.

[danny-avila]

@danny-avila I understand your concerns regarding the potential performance impact of adding automatic filename and line number logging. However, I believe the benefits of this feature could significantly outweigh the concerns for several reasons

1. **Developer Efficiency**: Automatically adding file names and line numbers to logs enhances developer productivity and debugging efficiency. By making log statements clickable in environments like VS Code, developers can quickly navigate to the source of an issue, reducing the time spent on tracing log origins manually.

2. **Maintainability:** With this feature, the need to manually update log statements with file names and line numbers is eliminated. This reduces human error and ensures that logs are always accurate, even as the codebase evolves and files are refactored or moved.

3. **Performance Considerations**: While it's valid that adding regex processing could introduce some overhead, the impact might be less significant than anticipated. We can mitigate performance concerns by:


* Changing it to work only on DEBUG messages and not INFO

* Remind users that production environments where performance is critical should not have DEBUG logging on.

* Later in the project, if we find it to be a problem we can implement a lightweight method to capture filenames and line numbers, possibly using native JavaScript capabilities instead of regex.

As Kent Beck says “Make it work. Make it right. Make it fast”, Developer Efficiency and Maintainability should be handed sonner in the project lifecycle then Performance ...

I understand, but for debug logs, it's not quite as important. It is better suited to log the values being passed. In my opinion, since they are more frequent, we should avoid any additional regex if we can. Also, using error stacks for control flow or program logic is generally not recommended due to potential performance implications and the possibility of varying stack trace formats across different Node.js versions. Most "get current line" solutions are just this, a double whammy of this method + regex getting called rather frequently and performance takes a hit.

possibly using native JavaScript capabilities instead of regex.

Great idea, we can utilize __filename and __dirname to this effect, they may need to be passed to the logger, so for debug logs we can at least get 2 of 3 desired effects: filename/path, but not the current line.

The error logger already includes stack trace, and we are not creating an error object ourselves, but we can maybe improve this by

1 - formatting it better
2 - creating a stack trace in case the object passed is not actually an Error.

I'll reopen this PR in case you are willing to try that approach, but if not, feel free to close.

[ido777]

Cool, let's ensure we're on the same page. I'll restate the points for clarity—please confirm or correct them:

Requirements:

General:

• Aim for detailed logging to assist developers while balancing system performance.
• Prefer native solutions to minimize processing overhead.

Debug Logs:

• Exclude regular expressions to reduce performance impact.
• Focus on logging values passed, rather than using error stacks for line numbers.
• Employ native JavaScript capabilities, specifically __filename and __dirname, for logging the filename/path efficiently.
• By default, line numbers will not be included in debug messages.

Error Logs:

• Maintain inclusion of stack traces as currently implemented.
• Enhance the clarity of stack trace formatting.
• Generate a stack trace automatically if the object passed is not a genuine error, to ensure detailed logging.

Questions:

• For "formatting it better" could you specify the desired changes to the current or proposed format?

• I suggest using a configuration variable to decide whether to add line numbers in debug logs, balancing detailed logging against performance. By default, the production environment should be optimized for performance, but developers could enable more detailed logging in development settings if needed. Does this approach sound reasonable?