Nginx Access Logs => Metrics?

[Zren]

Do you have access to /var/log/nginx/*.log files? You could perform some wizardry with those files to count the meta/update/install requests filtered by timestamp / ip / user agent.

[Martii]

Nope. (as in doesn't exist)

[Martii]

I would be open to having to viability/feasibility results on https://www.npmjs.com/package/throttled-request if it's worth it... it's about the only thing on npmjs.com that I've found.

There's also this, https://www.npmjs.com/package/throttle-function, but it's even older.

---

If I can one of these confirmed as usable and possibly a PR for it... I can release the @updateURL requirement.

[Zren]

I meant for serverside logs. You dont have console access? Bleh. I mean,
we could do a web ui for it too but it would use cron to schedule a task to
generate a page.

Then do you have a log dump with morgan logging turned on of the past
hour/24h? I could parse out all the other crap and format it nicely so we'd
have an idea of the number of requests were getting.

If you are interested, send it to my email since there might be something
in there. Otherwise i could just write some scripts for you to run.
On 11 Apr 2016 3:32 a.m., "Marti Martz" notifications@github.com wrote:

I would be open to having to viability on
https://www.npmjs.com/package/throttled-request if it's worth it... it's
about the only thing on npmjs.com that I've found.

There's also this, https://www.npmjs.com/package/throttle-function, but
it's even older.

—
You are receiving this because you authored the thread.
Reply to this email directly or view it on GitHub
#966 (comment)

[Martii]

You dont have console access?

I do... however still prefer to keep this inside the project and off the OS CLI as much as possible for cross-platform considerations... although it's been a really long time since I've tried Windows with our project with Git Bash.

Then do you have a log dump with morgan logging turned on of the past hour/24h?

I do not. See here and #430 esp. the dismissal but I'm willing to consider this a new day. The stdout and stderr messages are inclusive with the console object.

Otherwise i could just write some scripts for you to run.

I'd be willing to look at them for sure to ease up some typing.

[Zren]

I do...

cool

I'd be willing to look at them for sure to ease up some typing.

So will the scripts be able to parse /var/log/nginx/access.log? Or is it another file? Does Nodejitsu use even use nginx? cd /var/log/nginx/ && ls

[Martii]

Does Nodejitsu use even use nginx? cd /var/log/nginx/ && ls

It's not nodejitsu anymore ... if you do a $ whois on our domain name it will tell you who it is... the VPS doesn't have that folder from the "Nope" that I put above.

I've already just blocked two new IPs in the 21 minutes I've been on the keyboard as the manual instance in my shell was filling up with it.

[Zren]

So what's your tech stack then? Just a node instance on a DO droplet?

the manual instance in my shell was filling up

You log stdout to a file right, or do you have to start a new instance with debug enabled whenever you want to check the logs? If you log to file, you can use the tail -f filename.log to watch it.

[Martii]

node instance

Correct and usually a process manager to keep it alive... one of them which strips out date/times too which is annoying. We had to roll back to forever because the other one lost all instances launched when memory went away but I might have that more managed with the recent kernel update and this code.

log stdout to a file right

See here again and this as to why we're not logging fully in production. nodejitsu had this issue as well and I'd rather not store something that could be handled in memory and or with a throttling package. e.g. if the function is requested too many times from the same ip send them off to 503... or the request itself... however that package I mentioned doesn't appear to support the express .get and .put shortcuts... just reading though haven't tried it yet.

do you have to start a new instance with debug enabled whenever you want to check the logs?

This is a last resort as that sends out tons of info and is why I created #430 along with debug, dev and pro modes... plus you would see dbg on production next to OpenUserJS in the upper left corner.

Right now I'm twiddling with logging, to the terminal for now, the requests to .user.js ... the IP, the Accept header, script route, and UA. That's how I'm establishing monitoring statistics for #957.

you can use the tail -f filename.log to watch it.

Been a while since I've seen that command... thanks for the tip... will help if we log for sure and need a quick shell snapshot. I'm contemplating doing something similar in the Admin tools as well but not sure how much bandwidth that would use.

[Zren]

If you don't want requests being logged with the other logs, log them directly to file.

• https://github.com/expressjs/morgan#single-file

Then rotate the log file + compress them. I'm sure it should have a way to limit the size taken up somewhere as well. Nginx uses logrotate but that won't work for us since the filestream needs to be restarted probably. It looks like there's a https://github.com/dstokes/logrotate-stream package that could work.

So something like this:

var logrotateStream = require('logrotate-stream');
var accessLogStream = logrotateStream({
  file: './logs/app.log',
  size: '1m', // Should sate your worries about that issue
  keep: 100, // 100mb dedicated to logs
  compress: true, // well not really 100mb
});
app.use(morgan('combine', { stream: accessLogStream }));

I haven't tested this, I don't even have node installed atm I think. I'll setup a load test in a bit.

[Zren]

So with the following app:

var express = require('express')
var fs = require('fs')
var morgan = require('morgan')

var app = express()

var logrotateStream = require('logrotate-stream');
var accessLogStream = logrotateStream({
  file: './logs/app.log',
  size: '1m',
  keep: 100,
  compress: true,
});
app.use(morgan('combined', { stream: accessLogStream }));

app.get('/', function (req, res) {
  res.send('hello, world!')
})


app.listen(3000);

and using loadtest with loadtest http://localhost:3000 (requesting ~900 requests/sec) filled a 1 mb log every 30s or so. They crunched to 3kb but that's not very helpful since it's the same thing repeated.

Edit: The combined format is probably good enough for this. It has ip, timestamp, method, path, responseCode and userAgent. We could probably look into seeing if we can log certain headers as well.

::ffff:127.0.0.1 - - [11/Apr/2016:20:47:08 +0000] "GET / HTTP/1.1" 200 13 "-" "loadtest/1.3.5"

[Martii]

They crunched to 3kb but that's not very helpful since it's the same thing repeated.

What do you mean by this?

logrotate-stream

If we do log anything this massive I would want the rotate to tar.xz these on rotation automatically. e.g. not a cron job. This is a reason why we should keep these things in the project and not on the OS CLI. (P.S. I had to move exec calls to private because on low memory it would crash the server... so native node would be nice to have)

We could probably look into seeing if we can log certain headers as well.

This in mandatory right now.

Let me think about it some more... working on a few other ideas that may help. Appreciate the package refs as the terminology is all over the place with this kind of system management.

[Martii]

[11/Apr/2016:20:47:08 +0000]

Our other process manager date/times stamps too... and eventually we'll go back to that.

[Zren]

What do you mean by this?

When a log is rotated out when it hits the maximum filesize, it gets zipped.

Edit: Should note that I set it to size: '10m', so it wasn't rotating out so quickly. They zipped to half a megabyte which ain't bad.

If we do log anything this massive I would want the rotate to tar.xz these on rotation automatically. e.g. not a cron job. This is a reason why we should keep these things in the project and not on the OS CLI.

That's what logrotate-stream does. It's a pure Node.JS solution. It's basically the same thing as logging to a file except it checks the filesize of the log after writing to it, and rotates it out. Rotating means it renames it to filename.0 then compresses it then renames it to filename.1 or whatever is available.

It should also limit the amount of logs rotated out as well keep: 100 will keep 100 old logs before it starts deleting the oldest.

[Martii]

Sure would be nice if it did xz... that's usually about 60% smaller for these types of logs. I already have a rotate function in for some things CLI but will look into it for this application.

[Martii]

Just for stats pre analysis I logged ~ 12 minutes and that generated an uncompressed log of 494028B (482KiB) with a routine I have in place to with the filtering of the problematic IPs with this sort of output :

::ffff:xxx.xxx.xxx.xxx text/x-userscript, */* /install/Kizuna/Nyaa_Magnet_Links.user.js Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/51.0.2683.0 Safari/537.36