Better logging?
Closed this issue · 8 comments
Hey!
I am struggling a lot to debug an issue because boring appears to have very limited logging facilities. I set BORING_LOG_FILE=something and DEBUG=1, but I found these vars in the source code, documenting them would be great.
And i got
[17:22:07] INFO Daemon starting
[17:22:07] DEBUG Received object: &{List { 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:22:07] INFO Received command {List { 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:22:07] DEBUG Sending: {true map[]}
[17:22:19] DEBUG Received object: &{Open {mongodev 27017 development-0.cmpskmkqxq3a.eu-central-1.docdb.amazonaws.com:27017 ssh.dev.robosales.cz ubuntu ~/.ssh/id_ed25519 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:22:19] INFO Received command {Open {mongodev 27017 development-0.cmpskmkqxq3a.eu-central-1.docdb.amazonaws.com:27017 ssh.dev.robosales.cz ubuntu ~/.ssh/id_ed25519 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:22:19] INFO Opened tunnel mongodev...
[17:22:19] DEBUG Sending: {true map[]}
[17:22:56] DEBUG Received object: &{Close {mongodev 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:22:56] INFO Received command {Close {mongodev 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:22:56] INFO Received stop signal for mongodev...
[17:22:56] INFO Closed tunnel mongodev
[17:22:56] ERROR could not accept: accept tcp 127.0.0.1:27017: use of closed network connection
[17:22:56] DEBUG Sending: {true map[]}
[17:22:59] DEBUG Received object: &{Open {mongodev 27017 development-0.cmpskmkqxq3a.eu-central-1.docdb.amazonaws.com:27017 REDACTED.cz ~/.ssh/id_ed25519 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:22:59] INFO Received command {Open {mongodev 27017 development-0.cmpskmkqxq3a.eu-central-1.docdb.amazonaws.com:27017 REDACTED.cz ~/.ssh/id_ed25519 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:23:00] INFO Opened tunnel mongodev...
[17:23:00] DEBUG Sending: {true map[]}
[17:23:41] DEBUG Received object: &{List { 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:23:41] INFO Received command {List { 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:23:41] DEBUG Sending: {true map[mongodev:{mongodev 27017 development-0.cmpskmkqxq3a.eu-central-1.docdb.amazonaws.com:27017 REDACTED.cz ~/.ssh/id_ed25519 0 -> open 0xc000206310 0xc0000ba280 0xc0002422d0 0xc000224400 0xc0002062a0}]}
[17:23:44] DEBUG Received object: &{Close {mongodev 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:23:44] INFO Received command {Close {mongodev 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:23:44] INFO Received stop signal for mongodev...
[17:23:44] INFO Closed tunnel mongodev
[17:23:44] DEBUG Sending: {true map[]}
[17:23:44] ERROR could not accept: accept tcp 127.0.0.1:27017: use of closed network connection
[17:23:46] DEBUG Received object: &{List { 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:23:46] INFO Received command {List { 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:23:46] DEBUG Sending: {true map[]}
[17:24:30] DEBUG Received object: &{Open {mongodev 27017 development-0.cmpskmkqxq3a.eu-central-1.docdb.amazonaws.com:27017 REDACTED.cz ubuntu ~/.ssh/id_ed25519 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:24:30] INFO Received command {Open {mongodev 27017 development-0.cmpskmkqxq3a.eu-central-1.docdb.amazonaws.com:27017 ssh REDACTED.cz ~/.ssh/id_ed25519 0 -> closed <nil> <nil> <nil> <nil> <nil>}}
[17:24:30] INFO Opened tunnel mongodev...
[17:24:30] DEBUG Sending: {true map[]}
but I can't still reach the mongo. I can do it manually through ssh -L just fine though. Is there another log which would show me more information?
I mean I assume the ssh tunnel dies due to configuration issue I just don't know what the conf issue is
i got it working.. it was an issue elsewhere. But the logging would still be great
Hi, hmm, it looks like the connection can be established (so likely not ssh config issue) and then it is explicitly closed after about 45 seconds via boring close <name> . At least the logs indicate the daemon receiving a Close command from the CLI...
Also great idea to document those ENV variables, I'll add that soon!
Hi, hmm, it looks like the connection can be established (so likely not ssh config issue) and then it is explicitly closed after about 45 seconds via
boring close <name>. At least the logs indicate the daemon receiving a Close command from the CLI...
The CLI closing was me, because I tested the connection and thought it wasn't established correctly. But it turns out I was using flawed flawed method to test the connection so it's possible it worked the whole time 🤦
INFO Opened tunnel mongodev...
Does this mean the connection was successfully established and didn't die somewhere? Like e. g. the target server having tunneling disabled or something. Would it show up in the logs if the target server died? Like a reboot perhaps
Like it wasn't very clear to me that the connection was established successfully AND that it is still alive. But perhaps that's just the exhaustion speaking
Yes, the "Opened tunnel" implies that the SSH connection was established successfully and that the tunnel is now listening on the specified port. If it didn't, there would be an appropriate error message in the CLI already. If the connection dies (e.g. due to a server reboot or other connection loss), boring transitions into an (exponential backoff) re-connection loop, and this will also be logged.
But I agree with you, I'll try to make it a bit clearer in an upcoming release :) Anyway thanks for your interest in the project!
Closing this then, as the original issue seems to be resolved. I'll keep in mind to make the logs a bit more explicit.