Add access and error logs to undertow

[bdw429s]

Most web servers all have the ability to enable 'access' and 'error' logs that log every request coming in and some basic things about those requests. Add in the same ability to Runwar.

https://ortussolutions.atlassian.net/browse/COMMANDBOX-720

[denuno]

The next release adds these options:

  -logDir,--log-dir <path/to/log/dir>
    Log directory.  (WEB-INF/logs)

  -logaccess,--logaccess-enable <true|false>
    Enables or disable access logging [default:false]

  -logaccessbasename,--logaccess-basename <basename>
    Access log file base name/prefix [default:access]

  -logaccessdir,--logaccess-dir </path/to/dir>
    Log access directory

  -logbasename,--log-basename <basename>
    Log file base name/prefix [default:server]

  -logrequests,--logrequests-enable <true|false>
    Enables or disable request logging [default:false]

  -logrequestsbasename,--logrequests-basename <basename>
    Requests log file base name/prefix  [default:request]

  -logrequestsdir,--logrequests-dir </path/to/dir>
    Log requests directory

So we have access and request logging now, dunno about error beyond what's there for the server itself, or the engine's.

[bdw429s]

Cool. What's the difference between "access" and "request"?

Also, will there be any log rotation options?

[denuno]

Access is in the "common" format, and is the usual one you'd use for statistics, request is for debugging only, dumps the whole request. There's rotation on the access log by date by default.

[bdw429s]

Cool, one feature I've wanted to have is the ability to tail the incoming requests. Right now there's just way way to much crap in the debug output to even follow. We still need to seriously reduce that.

[denuno]

The idea behind the different log levels was to be able to ratchet the output up and down. Maybe info would be better than debug? FWIW, I ditch the LogSubverter for 3.8, instead just using slf4j, since we're including it for other stuff anyhow. That should I think give more options to configure output by class and whatnot.

If you've got it in debug mode, you can append /dumprunwarrequest to the request and it will dump out the exchange as well.

[bdw429s]

Maybe an info logging level is what we need. I was trying to debug a server just this week and wanted to keep track of the CF requests as they came in so I had started the server like so:

start --debug --console

But every browser refresh had a page of Tuckey debugging plus a page of Undertow JSON gibberish (that to this day I've never understood, used, or wanted). And worse, it was that times two because of the dumb /favicon.ico request that would come through. The console output was practically useless. All I really wanted was a single line of output for each request to ColdFusion and possibly an additional line that showed me what the request had been rewritten as.

If we can find a way to satisfy that use case, I'll be a happy person.

[denuno]

One person's trash is another person's treasure :smiley:

The access log should be a single line per request, and we can even do various formats and whatnot, though it's hard-coded for the "common" format as of now.

FWIW, with linux it's common to want just lines with X, so it's also common to pipe stuff through things like grep or whatnot... 'cause *nix is kewl! Bet you could do something like that within commandbox.

I'm fine with adding more flags and whatnot, for turning logging of things on and off... theoretically we can toggle logging, and even log levels, per-class now, but I haven't looked into it much.

At any rate, I'm going to close this one, it'll be in the next release.

[bdw429s]

@denuno Circling back to this ticket for testing now.

dunno about error beyond what's there for the server itself, or the engine's.

I'm just going after the same basic "error" log that you'd get in an Apache or Nginx web server.
https://httpd.apache.org/docs/1.3/logs.html#errorlog

Are we able to get this same information from Undertow's web server?

There's rotation on the access log by date by default.

Is that to say that there isn't rotation on the request log or did you mean to imply that both logs have automatic rotation?

[bdw429s]

Testing with these settings:

--logaccess-enable  true
--logaccess-basename  access
--logaccess-dir  D:\.Command Box/server/F8D83DF1D1B63549681065C2EA22ABC4-test$/adobe-2016.0.05.303689/logs

But it produces a log file named accesslog with no period in there for the file extension. You showed the default log name as access with no period. Should I be including a period in the log file name or is this a bug?

[bdw429s]

What does this error mean?

[INFO ] runwar.server: processoutput: [ERROR] runwar.server: Request log output currently goes to server.log

[denuno]

There should be rotation on everything now, configurable (generally) by date/size/etc.. The logging appenders can be configured at runtime, so stuff can go anywhere-- files, streams, logstash or whatnot. The separate error log is just a matter of saying "log these levels to this file, these to this other", and "these" for one being solely error. :smiley:

As for that missing period... I think the date is supposed to be in there (though I'd rather it not get added until the log rolls myself), but come to think of it I thought the date should be in the server log filename too... hmm...

That ERROR log line is just cruft, I'll nix it now.

[bdw429s]

There should be rotation on everything now

Great.

The logging appenders can be configured at runtime, so stuff can go anywhere-- files, streams, logstash or whatnot.

Oh, that's interesting. I don't know what it would look like to do that, so I'd love to see an example if you can cook one up. I can add it to the CommandBox docs for people to play with.

The separate error log is just a matter of saying "log these levels to this file, these to this other", and "these" for one being solely error

Yep, I get that you're saying it's just a subset of information. Every other web server I've seen has "error" logs and it's been pointed out a couple times now that lack of proper access/error logs is one of the things that prevents CommandBox/Runwar from being a "real" web server like IIS/Apache/Nginx. I don't the usefulness of an error log or how many people use it, but I figured if it's easy to do, let's take away that "reason" why CommandBox/runwar don't do everything that other web servers do! :)

As for that missing period... I think the date is supposed to be in there (though I'd rather it not get added until the log rolls myself),

I agree very much so. The reason is I want to add a convenience command to easily tail each of our log files (server [which already exists], access, request, error, rewrite). I need to be able to know the name ahead of time so I can tail it so no dates please until they've rolled.