Better error message if birdseye fails to start
alexmojaki opened this issue · 19 comments
The first time I tried to start birdseye it failed because the port was taken (see #7). It took some guessing to figure out the problem because all it told me was that the exit code was 1. Some output from the failed command would be helpful, even just the last line.
This would be nice, but the problem is that flask logs to stderr for some ungodly reason. This makes it difficult to tell what is an error and what is just normal logging.
I did a bit of googling and it looks like it can be fixed by changing the logging settings. Google wasn't kind enough to give me an exact answer on this :/
Logging to stderr is normal.
If birdseye hits an exception in startup then the last line will be that exception, not logging.
To be extra sure, find the last line that case-insensitively contains the word 'error' or 'exception' in it, or just the last line if there is none, and display it and the two lines after it if they exist.
If birdseye hits an exception in startup then the last line will be that exception, not logging.
To be extra sure, find the last line that case-insensitively contains the word 'error' or 'exception' in it, or just the last line if there is none, and display it and the two lines after it if they exist.
Yeah, easy enough to detect on my end I suppose.
Logging to stderr is normal.
That should definitely not be normal. I'll raise an issue with flask.
// flask logs everythihng to stderr
this.child.stderr.on("data", data => {
console.log(data.toString());
if(data.toString().includes("Traceback (most recent call last)")){
// we have an exception :(
vscode.window.showErrorMessage(data.toString())
}
});Logging to stderr is standard practice throughout Python. Here's an example:
python -c 'import logging; logging.basicConfig(level="INFO"); logging.info("Hello")' 2> stderr.txt
(2> redirects stderr)
I would say it's standard practice in most languages. One reason is that other output which is meant to be piped into another process is kept separate from logging. In my company we've had problems before because a third party library had some output on stdout, either logging or something similar.
It is also possible to have an error without a traceback. Here's a concrete example. I am likely to switch to using argparse once more arguments are required (like changing colour scheme). Then the port will be an optional argument, not a positional one. Which means that when you run it it will fail, something like this:
$ python -c 'import argparse; parser = argparse.ArgumentParser(); parser.add_argument("--port", default=7777); parser.parse_args()' 1234
usage: -c [-h] [--port PORT]
-c: error: unrecognized arguments: 1234So if you stick to this approach, users who upgrade birdseye will find it stop working and won't know why.
Also, what does it look like to show a long traceback in an error message?
I would say it's standard practice in most languages. One reason is that other output which is meant to be piped into another process is kept separate from logging.
0_o TIL. Good explanation, that makes more sense now. I also looked up the official definition of stdout / stderr and it agrees with you:
stdout
The standard output stream, which is used for normal output from the program.
stderr
The standard error stream, which is used for error messages and diagnostics issued by the program.
So "stderr" is not named very well. It's more like "stdDiagnostic" or "stdLogs". I would be nice if instead of just the two streams (stdout, stderr) we had 6 - stdout, ERROR,WARN,INFO, DEBUG, and ALL. But would be more complex I suppose.
It is also possible to have an error without a traceback.
Figures. I'll adjust my logging accordingly.
this.child.stderr.on("data", data => {
data = data.toString().toLowerCase()
console.log(data);
if(data.includes("traceback (most recent call last)") || data.includes("error") || data.includes("exception")){
vscode.window.showErrorMessage(data)
}
});If Argument error:
If error in birdseye:
Hovering over the error will give you a little dropdown icon which you can click to get this:
What happens if you debug a function called "error" and visit the relevant page in birdseye?
god damnit XD
let me check.
yeah that causes the error message to appear when you click on the function.
Workaround:
if(!data.startsWith("127.0.0.1") && // anything starting with 127.0.0.1 will just be normal web requests
(data.includes("traceback (most recent call last)") || data.includes("error") || data.includes("exception"))){
vscode.window.showErrorMessage(data + ' Please raise an issue: https://github.com/Almenon/birdseye-vscode/issues')
}Why not put the check in the error and exit handlers instead?
Also I'm worried that if there's an error after it's been running for a while it'll spill out all the logs and the message will be huge.
And finally whatever you put in that error message shouldn't be lowercased.
Why not put the check in the error and exit handlers instead?
Error, ironically enough, is not emitted upon error. It has three specific use cases.
https://nodejs.org/api/child_process.html#child_process_event_error
The 'error' event is emitted whenever:
The process could not be spawned, or
The process could not be killed, or
Sending a message to the child process failed.
Exit happens along with the exception but it only provides the exit code and signal.
Event: 'exit'#
code The exit code if the child exited on its own.
signal The signal by which the child process was terminated.
Also I'm worried that if there's an error after it's been running for a while it'll spill out all the logs and the message will be huge.
Eh, no big deal. The message expands and unexpands. More info is better than less and errors (hopefully) should not happen often.
And finally whatever you put in that error message shouldn't be lowercased.
Why would case matter in a exception???
thinks for a second
Oh right, linux OS have case-sensitive paths. I'm on windows so I'm not used to that :/
Then use the data handler to store the data in a variable and show it in the exit handler.
import * as vscode from "vscode";
import { spawn, ChildProcess } from "child_process"
/**
* function taken from Duroktar's Wolf Ext
* Calls postinstallhook if user accepts prompt and installation is successful
* @param postInstallHook
*/
export class birdseye{
child: ChildProcess;
running = false;
exitRequested = false;
exception:string;
start(port="7777", pythonPath='python'){
this.exitRequested = false
this.child = spawn(pythonPath, ["-m", "birdseye", port]);
this.running = true
this.child.stderr.on("data", data => {
data = data.toString()
console.log(data);
if(this.hasError(data)){
// save exception for later to show user when birdseye exits
this.exception = data
}
});
this.child.on('error', err => {
this.running = false
vscode.window.showErrorMessage("could not start birdseye! error: " + err.message)
// technically this could also happen if birdseye could not be killed
// or if sending a message to it failed
// but we are not sending messages, and we use SIGKILL, so both are unlikely
})
this.child.on("exit", code => {
if(!this.exitRequested){
vscode.window.showErrorMessage(
`birdseye exited due to an error :( error code: ${code} Exception: ${this.exception}
Please raise an issue: https://github.com/Almenon/birdseye-vscode/issues`
)
this.running = false
}
});
}
stop(){
if(this.running){
this.exitRequested = true
this.child.kill('SIGKILL')
this.running = false
}
}
private hasError(data:string){
data = data.toLowerCase()
return !data.startsWith("127.0.0.1") && // anything starting with 127.0.0.1 will just be normal web requests
(data.includes("traceback (most recent call last)") || data.includes("error") || data.includes("exception"))
}
}Finally done! See 2f9681b . Only change I would like to make is to refactor VSCode dependencies out to decouple the birdseye logic, but that can wait for another time.
I'm going to eat dinner now so you better like what you got :P
Awesome :)