Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Remove the logs printed from the listeners #2040

Closed
shafreenAnfar opened this issue Oct 13, 2021 · 12 comments
Closed

Remove the logs printed from the listeners #2040

shafreenAnfar opened this issue Oct 13, 2021 · 12 comments
Labels
module/http Team/PCM Protocol connector packages related issues Type/Improvement

Comments

@shafreenAnfar
Copy link
Contributor

shafreenAnfar commented Oct 13, 2021

Even though in the case of listeners there is no way to add logs when the biding happens, etc, users still can add a log in the service init. It is not the same but good enough. Eg,

configurable int port = 9090;
service / on new http:Listener(port) {

    function init() {
        log:printInfo("Started HTTP/WS listener", host="0.0.0.0", port=port);
    }

    resource function get greeting() returns string {
        return "Hello, World!";
    }
}
time = 2021-11-11T11:55:05.737+05:30 level = INFO module = "" message = "Started HTTP/WS listener" host = "0.0.0.0" port = 9090

On the other side, these logs gets in the way when developing other libraries (which is a common usecase for standard libraries). For instance, GraphQL and WebSub both use HTTP library. They have no way to suppress or customize the HTTP log printed from the listener.

Eg - [ballerina/http] started HTTP/WS listener 0.0.0.0:9090

@shafreenAnfar shafreenAnfar added Type/Improvement module/http Team/PCM Protocol connector packages related issues labels Oct 13, 2021
@shafreenAnfar shafreenAnfar changed the title Remove logs printed from the listeners Remove the logs printed from the listeners Nov 11, 2021
@shafreenAnfar
Copy link
Contributor Author

Please note that in the case of an error, error logs will be printed.

@chamil321
Copy link
Contributor

chamil321 commented Nov 15, 2021

@shafreenAnfar I hope the reason behind the change is to hide the internal protocol details when we using the dependent modules such as WebSub and GraphQL. But this change can reduce some important info such as host and port which provided implicitly. Also the end user also does not receive a strong signal saying the listener is ready to serve request.

If the issue is with the prefix of [ballerina/http] we still can remove it from the HTTP package and have the remaining as an implicit indication of listener state without customising to a protocol.

Started listener 0.0.0.0:9090

@shafreenAnfar
Copy link
Contributor Author

I hope the reason behind the change is to hide the internal protocol details when we using the dependent modules such as WebSub and GraphQL. But this change can reduce some important info such as host and port which provided implicitly. Also the end user also does not receive a strong signal saying the listener is ready to serve request.

Well, when it comes to listeners, we don't use implicit host and port. This is similar to Java server socket. Because, if you use an implicit port, you don't know which port to send request to.

If the issue is with the prefix of [ballerina/http] we still can remove it from the HTTP package and have the remaining as an implicit indication of listener state without customising to a protocol.

It is not the prefix but the entire log is the problem. We can not just get rid of the prefix as it is a key part of the any log entry. Users need to know who printed this log.

IMO, Ballerina is a programming language and it gives enough room to let users print what they want. We as standard library developers should not have an opinionated stand on this.

@chamil321
Copy link
Contributor

I hope the reason behind the change is to hide the internal protocol details when we using the dependent modules such as WebSub and GraphQL. But this change can reduce some important info such as host and port which provided implicitly. Also the end user also does not receive a strong signal saying the listener is ready to serve request.

Well, when it comes to listeners, we don't use implicit host and port. This is similar to Java server socket. Because, if you use an implicit port, you don't know which port to send request to.

I must have missed the log part, in-fact I meant the implicit log which provided stating the user provided host port.

If the issue is with the prefix of [ballerina/http] we still can remove it from the HTTP package and have the remaining as an implicit indication of listener state without customising to a protocol.

It is not the prefix but the entire log is the problem. We can not just get rid of the prefix as it is a key part of the any log entry. Users need to know who printed this log.

IMO, Ballerina is a programming language and it gives enough room to let users print what they want. We as standard library developers should not have an opinionated stand on this.

Yeah agree. User can go ahead with some logs based on their requirement

@chamil321
Copy link
Contributor

chamil321 commented Nov 15, 2021

Quick question: To make it consistent, we have to remove the listener stop log as well right?
[ballerina/http] stopped HTTPS/WSS listener 0.0.0.0:9090

But user does not have proper way to log that if needed when the service declaration is used. But they can used lifecycle method(GracefulStop())

@nuwand
Copy link

nuwand commented Dec 15, 2021

This is a major usability issue. As a Ballerina user I am writing a service and running it. I expect to see a message saying my service is ready. But all I see now is "Running executable". This is very confusing. What is "executable"? Is it still compiling? How am I supposed to know my service is ready to receive requests?

@shafreenAnfar
Copy link
Contributor Author

As mentioned in the description if an explicit log is expected to be printed, service init can be used. But that is a choice of the developer. One might expect a log but the other might not. Of-course there can be a millisecond difference between the log and the actual binding but it is not a major problem. Because this log is merely printed for a human to read.

Systems don't use logs to know if the service is ready. For instance in k8s you can do a readiness probe to determine if the pod is ready to serve traffic.

Even go lang standard library has high level abstractions [1] for writing services and they don't print a log either. I guess for the same reasons.

P.S. Running executable is always printed when running an executable. To get some executable compilation must happen first. If there is some ambiguity, we need to improve the build tool.

[1] https://gobyexample.com/http-servers

@nuwand
Copy link

nuwand commented Dec 15, 2021

I don't think it's right to compare Ballerina with Go. Unlike Go, the concept of services is fundamental to Ballerina. The problem is that as a developer if I implement a service in Ballerina and run it, I see no indication it started. The printed message is confusing and doesn't tell me its ready. It is the first user experience that is at stake here. Of course we can argue saying the developer can print a log if he/she wants to, and yes we can use probes and stuff in production to determine readiness. But at the end of the day if the first user experience is bad, none of that would matter.

@shafreenAnfar
Copy link
Contributor Author

Interesting, I thought for a human Running executable means the program is ready. You think printing a default log with host and port as additional information leads to a meaningful difference in user experience ?

Maybe I am missing out something :). If the Ballerina community also thinks the same, we can certainly consider another alternative for the original problem.

Yes, one to one comparison with go is not right. That is why it is not there in the original description. However, it is not that far away either in terms of starting a HTTP service. But the point is none of the standard libraries I know of print info logs. Firstly, because as mentioned in the description standard libraries are used to build other libraries as well. For instance, HTTP is used to build GraphQL, WebSub and WebSubHub. WebSub is used to build Github Webhook connector. This becomes more common for libraries such as TCP. In all those cases, info logs gets in the way. Secondly, Ballerina being a programing language users always can print the log if they want it.

@sanjiva @sameerajayasoma if you all have any opinion on this, do let us know.

@nuwand
Copy link

nuwand commented Dec 15, 2021

Printing the host and port are good to have, not mandatory.

The issue with Running is that it doesn't tell me that it is ready. Something like Process started would me more meaningful.

The issue with executable is that I wasn't dealing with any kind of executable till now. I just wrote some ballerina code and ran the run command. So I am left to guess what this executable means.

@sameerajayasoma
Copy link
Contributor

Usually, programming languages and standard library packages do not emit logs. Standard library packages are typically composed to build other packages, and such logs can be a nuisance for libraries built on top of standard libraries. I agree with @shafreenAnfar decision to remove logs emitted by the HTTP logs. This was discussed before as well.

There are three ways to run a compiled Ballerina program.

  1. bal run
→ bal run 
Compiling source
        sameera/mysvc:0.1.0

Running executable
  1. bal run foo.jar
→ bal run target/bin/mysvc.jar 
  1. java -jar foo.jar
→ java -jar target/bin/mysvc.jar

Most use the 1st or 2nd option during the development time and the 3rd in production.

I understand the usability issue here during the development time.

@nuwand
Copy link

nuwand commented Dec 21, 2021

I've watched quite a few first time users start a Ballerina program and say "It's stuck". That clearly shows there's a usability issue. Whether/How the same is done in other places is of lesser concern to me. Printing an ambiguous message that doesn't indicate the state of a process (but is supposed to) is very confusing, especially when it is used within platforms like Choreo (https://wso2.com/choreo).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
module/http Team/PCM Protocol connector packages related issues Type/Improvement
Projects
None yet
Development

No branches or pull requests

4 participants