search

OpenTreeOfLife / treemachine

Source tree graph database
Other
16 stars 6 forks source link

Less logging, more timestamps, please #162

Closed jar398 closed 9 years ago

jar398 commented 9 years ago

The treemachine console.log on ot20 (production) was 300+ Mbyte. This seems a bit excessive.

I've put a sample (tail -10000) here: http://mumble.net/~jar/tmp/console.tail

It would be useful to have timestamps, so we can match Java logging output to apache logs and get a hint at usage patterns.

Thanks

jar398 commented 9 years ago

data/graph.db/messages.log is also 300M.

josephwb commented 9 years ago

From @jar398 on IRC (for my own notes):

08:34 I think I would put: timestamp, arguments, nonce on call; then timestamp, nonce on return - the nonce being anything that could be used to match call and return, maybe a short unique id (counter) or even the first timestamp then if there’s a call without a return, we’ve nailed it

josephwb commented 9 years ago

@jar398 How does this look?

...
2015-02-10 16:44:39.977  Running subtree service.
    Argument 'ott_id' = 81443
    Argument 'node_id' = 3019459
    Error: Provide only one "node_id" or "ott_id" argument.
2015-02-10 16:44:39.998  Exiting subtree service on error.
2015-02-10 16:44:48.882  Running subtree service.
    Argument 'ott_id' = 81443
2015-02-10 16:44:49.525  Exiting subtree service on success.
2015-02-10 16:45:27.828  Running subtree service.
    Argument 'ott_id' = 814436732
    Error: Invalid "ott_id" argument.
2015-02-10 16:45:27.831  Exiting subtree service on error.
jar398 commented 9 years ago

This looks great - can you summarize what it was doing before that generated so much output, for comparison? I suspect that only logging requests will result in a large reduction, but I didn't know what it was doing before so can't be certain.

On Tue, Feb 10, 2015 at 4:46 PM, Joseph W. Brown notifications@github.com wrote:

@jar398 https://github.com/jar398 How does this look?

... 2015-02-10 16:44:39.977 Running subtree service. Argument 'ott_id' = 81443 Argument 'node_id' = 3019459 Error: Provide only one "node_id" or "ott_id" argument. 2015-02-10 16:44:39.998 Exiting subtree service on error. 2015-02-10 16:44:48.882 Running subtree service. Argument 'ott_id' = 81443 2015-02-10 16:44:49.525 Exiting subtree service on success. 2015-02-10 16:45:27.828 Running subtree service. Argument 'ott_id' = 814436732 Error: Invalid "ott_id" argument. 2015-02-10 16:45:27.831 Exiting subtree service on error.

— Reply to this email directly or view it on GitHub https://github.com/OpenTreeOfLife/treemachine/issues/162#issuecomment-73790753 .

josephwb commented 9 years ago

Apparently anything that prints to System.out gets logged in "console.log". This is stuff we (very verbosely) print to screen when using the command line. Since the plugins use the same code, that was what was causing the huge log files.