fix: include all log args in the log message
#2101
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
kittaakos
added
topic: code
per1234
reviewed
Jun 23, 2023
There was a problem hiding this comment.
I'm seeing a difference in the terminal output when I compare the build from this PR to the build from the main branch.
For example, here is the first part of the terminal output from main:
$ ./Arduino\ IDE.exe --log-level debug
Arduino IDE 2.1.1-snapshot-8f8b46f
Starting backend process. PID: 30036
Using browser-only version of superagent in non-browser environment
Configuration directory URI: 'file:///c%3A/Users/per/.arduinoIDE'
Configuring to accept webviews on '^.+\.webview\..+$' hostname.
2023-06-23T05:19:23.855Z root INFO Backend Object.initialize: 3.2 ms [Finished 0.645 s after backend start]
2023-06-23T05:19:23.855Z root INFO Backend Object.configure: 2.6 ms [Finished 0.645 s after backend start]
2023-06-23T05:19:23.856Z root INFO Backend MessagingContribution.onStart: 1.0 ms [Finished 0.645 s after backend start]
2023-06-23T05:19:23.856Z root INFO Backend OSBackendApplicationContribution.configure: 0.2 ms [Finished 0.668 s after backend start]
2023-06-23T05:19:23.856Z root INFO Backend DefaultWorkspaceServer.onStart: 0.2 ms [Finished 0.668 s after backend start]
2023-06-23T05:19:23.857Z root INFO Backend PluginLocalizationBackendContribution.configure: 0.1 ms [Finished 0.668 s after backend start]
2023-06-23T05:19:23.857Z root INFO Backend PluginLocalizationBackendContribution.initialize: 22.9 ms [Finished 0.669 s after backend start]
2023-06-23T05:19:23.857Z root INFO Backend TaskBackendApplicationContribution.onStart: 0.1 ms [Finished 0.669 s after backend start]
2023-06-23T05:19:23.858Z root DEBUG Starting the deployer with the list of resolvers [
LocalDirectoryPluginDeployerResolverWithFallback {},
GithubPluginDeployerResolver {
unpackedFolder: 'C:\\Users\\per\\AppData\\Local\\Temp\\github-remote',
request: ElectronBackendRequestService {}
},
HttpPluginDeployerResolver {
unpackedFolder: 'C:\\Users\\per\\AppData\\Local\\Temp\\http-remote',
request: ElectronBackendRequestService {}
},
LocalVSIXFilePluginDeployerResolver {
environment: PluginVSCodeEnvironment { environments: [EnvVariablesServer] }
}
]
2023-06-23T05:19:23.859Z root INFO Backend ElectronTokenBackendContribution.configure: 0.5 ms [Finished 0.669 s after backend start]
(note that it prints the list of "resolvers")
This is the start of the terminal output when using the build from this PR:
$ ./Arduino\ IDE.exe --log-level debug
Arduino IDE 2.1.1-snapshot-315e9eb
Starting backend process. PID: 15004
Using browser-only version of superagent in non-browser environment
Configuration directory URI: 'file:///c%3A/Users/per/.arduinoIDE'
Configuring to accept webviews on '^.+\.webview\..+$' hostname.
2023-06-23T05:28:13.801Z root INFO Backend Object.initialize: 3.0 ms [Finished 1.729 s after backend start]
2023-06-23T05:28:13.801Z root INFO Backend Object.configure: 2.4 ms [Finished 1.729 s after backend start]
2023-06-23T05:28:13.801Z root INFO Backend MessagingContribution.onStart: 1.0 ms [Finished 1.729 s after backend start]
2023-06-23T05:28:13.801Z root INFO Backend OSBackendApplicationContribution.configure: 0.2 ms [Finished 1.750 s after backend start]
2023-06-23T05:28:13.802Z root INFO Backend DefaultWorkspaceServer.onStart: 0.2 ms [Finished 1.750 s after backend start]
2023-06-23T05:28:13.802Z root INFO Backend PluginLocalizationBackendContribution.configure: 0.1 ms [Finished 1.750 s after backend start]
2023-06-23T05:28:13.803Z root INFO Backend PluginLocalizationBackendContribution.initialize: 21.3 ms [Finished 1.750 s after backend start]
2023-06-23T05:28:13.803Z root INFO Backend TaskBackendApplicationContribution.onStart: 0.1 ms [Finished 1.750 s after backend start]
2023-06-23T05:28:13.803Z root DEBUG Starting the deployer with the list of resolvers
2023-06-23T05:28:13.803Z root INFO Backend ElectronTokenBackendContribution.configure: 0.6 ms [Finished 1.751 s after backend start]
(Note that it does not print the list of "resolvers")
Thank you! Interesting one. I could reproduce it with CMD.EXE. ✅ ✅ ✅ ✅ ❌ The build from this PR with ✅ The build from this PR, normal start: |
|
OK. I have noticed that this kind of works. Same behavior on macOS, but I marked the relevant line with: |
TheiaBlueprint 1.38.0 works as expected. Starting the app with |
|
I have figured out the problem; IDE2 needs a better logger framework. The current file base logger is only part of the bundled application and has the following API: In Theia, the
|
- In the bundled application, the customized logger that writes the log files bogusly includes only the first message fragment in the log message. This PR ensures all message fragments are included in the final message before it is printed to the console/terminal and persisted to the rotating log files. - Includes messages with `debug` severity in the log. - Disables the ANSI coloring in the CLI daemon log by adding the `NO_COLOR=true` environment variable to the spawned CLI daemon process. - Trims trailing line ending of the daemon log. Signed-off-by: Akos Kitta <a.kitta@arduino.cc>
kittaakos
changed the title
debug messages in the log file
kittaakos
changed the title
args in the log message
So great you have found it. This was the root cause of why we've never seen the actual exception in error logs 🤦 Enabling the Please review. Thank you! |
3 tasks
3 tasks
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Motivation
debugmessages logged by the Theia logger were not forwarded to the file logger. This PR fixes it.Change description
files bogusly includes only the first message fragment in the log
message. This PR ensures all message fragments are included in the final
message before it is printed to the console/terminal and persisted to
the rotating log files.
debugseverity in the log.NO_COLOR=trueenvironment variable to the spawned CLI daemon process.Other information
Steps to verify:
debuglog level from a terminal. On macOS, it is similar to/Applications/Arduino\ IDE\ 2.1.0.app/Contents/MacOS/Arduino\ IDE --log-level debug.root DEBUG Board config changed:messages in the terminal.DEBUG Starting the deployer with the list of resolvers. You see the list of resolvers as a JSON string./Library/Logs/Arduino IDEon macOS. Verify that theroot DEBUG Board config changed:messages are inside the file. This does not work with2.1.0.Before:
After:
Before:
After:
Ref: #2100 (comment)
Reviewer checklist