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

How to change the prefix of the console output log? #7018

Closed
Niko-O opened this issue Oct 20, 2021 · 7 comments
Closed

How to change the prefix of the console output log? #7018

Niko-O opened this issue Oct 20, 2021 · 7 comments
Labels
Question Stale For auto-closed stale issues and pull requests

Comments

@Niko-O
Copy link

Niko-O commented Oct 20, 2021

Jetty version
According to the "Server" response header: Jetty(9.4.16.v20190411)

Java version
Output of java -version:

openjdk version "11.0.12" 2021-07-20
OpenJDK Runtime Environment (build 11.0.12+7-post-Raspbian-2deb10u1)
OpenJDK Server VM (build 11.0.12+7-post-Raspbian-2deb10u1, mixed mode)

Question

How can I configure the way that console outputs from my Java code gets logged?

I have an inherited project where I don't know exactly how everything is configured. Jetty is started by /etc/init.d/jetty9, which looks like it's this script:
https://www.apt-browse.org/browse/ubuntu/xenial/universe/all/jetty9/9.2.14-1/file/etc/init.d/jetty9
Logs are written to /var/log/jetty9/jetty-console.log and regularly archived.

When I output something to the console using System.out.println("Hello World");, The log file gets Oct 20 10:16:59 testpi jetty9[559]: Hello World appended. I use log4j to handle my logging needs, so I don't need the additional, redundand information to be prepended to every line.

There does not seem to be a console-capture.ini file. find / | grep console-capture.ini does not find anything.

@joakime
Copy link
Contributor

joakime commented Oct 20, 2021

The output format Oct 20 10:16:59 testpi jetty9[559]: Hello World is not something Jetty produces.

Jetty uses the format <timestamp:EEE MMM dd HH:mm:ss zzz yyyy.000> <level>: <name>:<thread-name>: <source> <msg>\n<throwable>

The jetty9[559] portion looks like it might be <service_name>[<pid>] (nothing in Jetty even attempts to identify the pid of the running JVM, nor even knows of the existence of the service name, nor would I even hazard a guess on how to do that from within Java)

The fact that it writes to /var/log/jetty9/jetty-console.log is also curious, as that's not a directory Jetty normally writes to, nor is it a filename that Jetty uses.
The linked jetty9 script is not what Jetty ships with.
That looks like something the ubuntu packaging folks have created.

That ubuntu script sets the jetty.logs system property, but only the DebugListener uses that system property (See the jetty-debug module), it also forces the timestamp on the name.
Aka ${jetty.logs}/yyyy_mm_dd.debug.log

So in conclusion, the filename, the location of the logs, and the format of the logs are all clues that tell us these logs are not from Jetty.

Incidentally, the linked init.d/jetty9 you provided is not compatible with the Jetty 9.4.x major version and has practically no resemblance to the jetty.sh that ships with Jetty.
(Reminder, Jetty versioning since 1995, is <servlet_support>.<major_version>.<minor_version>)
At this point only the ubuntu folks can help you with their highly customized Jetty version.

Also, Jetty 9.4.16 is subject to several security advisories, please do not use that version with a website that faces the public internet.
https://www.eclipse.org/jetty/security_reports.php

@joakime
Copy link
Contributor

joakime commented Oct 20, 2021

I use log4j to handle my logging needs, so I don't need the additional, redundand information to be prepended to every line.

Another thing to consider, have you configured your logging to capture all of the logging events from the other logging libraries and route them to log4j for logging?
If not, then you could be experiencing results of having an unconfigured logging library.

Common logging libraries (in order of most to least common):

  • java.util.logging (the most common)
  • log4j 1.x
  • slf4j
  • log4j 2.x (not compatible with 1.x out of the box, you have to do extra config work for that)
  • logback
  • java.lang.System.Logger (if using JDK 9+)
  • apache juli (if using jsp, or el)
  • commons-logging

If you use anything more than just raw Servlets (this includes JSP) you are subject to at least 2 or more of the above list.

The most common way to address this is to use slf4j to route all of the logging library events to slf4j, and then the slf4j binding implementation (like log4j 1.x) to write the content to disk.
Log4j 2.x as similar functionality, but in a more limited fashion (doesn't support nearly as many logging libraries).

Note: the fact that you report a System.out.println("Hello") is captured and written to disk, that is an entirely different story.

If something is doing that for you, then you should ...

  • configure log4j to not write to the Console (as that's a needless step).
  • configure log4j to write to the same log file location on disk (you should write to a different log file somewhere else on disk, that your jetty user has permissions to)

This behavior is probably something that the ubuntu folks have mangled into their custom init.d/jetty9 scripts.

@Niko-O
Copy link
Author

Niko-O commented Oct 21, 2021

Thank you for the extensive explanation!
I'll try to address your points in order.

That looks like something the ubuntu packaging folks have created.

I am on a Raspberry Pi. The fact that I linked a file relating to Ubuntu is concidental. I just googled the name of the author ("Philipp Meier") with some keywords.
You mentioned that I should ask "the Ubuntu folks" before. Knowing that I'm using a Raspberry Pi, does that change who I should ask? I'd assume so. The Raspberry Pi OS is AFAIK derived from Debian.

Also, Jetty 9.4.16 is subject to several security advisories

Well, that's... one of the many problems I'll have to work on eventually.

have you configured your logging to capture all of the logging events from the other logging libraries and route them to log4j for logging?

I don't think so. I simply added the log4j api and core JARs, added a simple log4j2.xml that logs to console and started using org.apache.logging.log4j.LogManager.getLogger(Foo.class).error("BarBaz");.
That logging works as I would expect. It outputs something like Oct 21 19:39:03 testpi jetty9[563]: <here my configured pattern> BarBaz to the file. And I would like to keep using the mechanism that packs up old/big log files.

If you use anything more than just raw Servlets

Also not sure. I have classes that extend HttpServlet and override doPost. Other than that I don't think there's much magic involved in the actual Java code that constitutes my program.

the fact that you report a System.out.println("Hello") is captured and written to disk, that is an entirely different story

Seems reasonable to me, though. log4j pipes to console, System.out.println also writes to console, the console output is mangled to include the additional date/time/device/process info and that is finally written to the log file.
Also, I just now found that there is an /etc/jetty9/console-capture.xml (as opposed to .properties) that contains "RolloverFileOutputStream"

<?xml version="1.0"?>
<!DOCTYPE Configure PUBLIC "-//Jetty//Configure//EN" "http://www.eclipse.org/jetty/configure_9_3.dtd">

<Configure id="logging" class="org.eclipse.jetty.util.log.Log">
    <New id="ServerLog" class="java.io.PrintStream">
      <Arg>
        <New class="org.eclipse.jetty.util.RolloverFileOutputStream">
          <Arg><Property name="jetty.console-capture.dir" deprecated="jetty.logging.dir" default="./logs"/>/yyyy_mm_dd.jetty.log</Arg>
          <Arg type="boolean"><Property name="jetty.console-capture.append" deprecated="jetty.logging.append" default="false"/></Arg>
          <Arg type="int"><Property name="jetty.console-capture.retainDays" deprecated="jetty.logging.retainDays" default="90"/></Arg>
          <Arg>
            <Call class="java.util.TimeZone" name="getTimeZone">
              <Arg><Property name="jetty.console-capture.timezone" deprecated="jetty.logging.timezone" default="GMT"/></Arg>
            </Call>
          </Arg>
          <Get id="ServerLogName" name="datedFilename"/>
        </New>
      </Arg>
    </New>

    <Get name="rootLogger">
      <Call name="info"><Arg>Console stderr/stdout captured to <Ref refid="ServerLogName"/></Arg></Call>
    </Get>
    <Call class="java.lang.System" name="setErr"><Arg><Ref refid="ServerLog"/></Arg></Call>
    <Call class="java.lang.System" name="setOut"><Arg><Ref refid="ServerLog"/></Arg></Call>
</Configure>

Is that what's doing this?

Also, is the /etc/init.d/jetty9 file executed magically by Linux or must that file be called by another process?

@joakime
Copy link
Contributor

joakime commented Oct 21, 2021

No the console-capture module (and xml) does not format it's logs like what you see.
And it does not use the filename jetty-console.log (it will always have a filename with a timestamp).

The fact that your log4j outputs only to Console means something else, outside of the JVM is creating those log files.
At this point, you should be looking at the debian service logging techniques, as that's what's its increasingly sounds like is happening.

@github-actions
Copy link

This issue has been automatically marked as stale because it has been a
full year without activity. It will be closed if no further activity occurs.
Thank you for your contributions.

@github-actions github-actions bot added the Stale For auto-closed stale issues and pull requests label Oct 22, 2022
@joakime joakime closed this as completed Oct 22, 2022
@Niko-O
Copy link
Author

Niko-O commented Jun 27, 2024

While updating to Jetty 10, I had to dive a bit more deeply into the whole setup. I found out that we used rsyslog, and I'm pretty sure that that's responsible for the additional output. With Jetty 10, we're using the console-capture module now, and that does not show this additional output.

Sorry for leaving this rotting for so long, but I just didn't get around to it earlier.

@joakime
Copy link
Contributor

joakime commented Jun 27, 2024

Jetty 10 is now at End of Community Support.

You should be using a supported version of Jetty now.
Jetty 12 is the currently supported version of Jetty.

If you still need javax.servlet support, you can use Jetty 12's ee8 environment to accomplish that.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Question Stale For auto-closed stale issues and pull requests
Projects
None yet
Development

No branches or pull requests

2 participants