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

Add rotated logs support #5

Merged
merged 2 commits into from
Jul 28, 2020
Merged

Conversation

flexoid
Copy link
Contributor

@flexoid flexoid commented Jul 26, 2020

The required enhancement was described in issue #4.

New flags help (from --help output)

log:
      --log.filename=            file to write logs to. Log to stdout if not specified [$CRONN_LOG_FILENAME]
      --log.max-size=            maximum size in megabytes of the log file before it gets rotated (default: 100) [$CRONN_LOG_MAX_SIZE]
      --log.max-age=             maximum number of days to retain old log files (default: 0) [$CRONN_LOG_MAX_AGE]
      --log.max-backups=         maximum number of old log files to retain (default: 7) [$CRONN_LOG_MAX_BACKUPS]
      --log.enabled-compress     determines if the rotated log files should be compressed using gzip [$CRONN_LOG_ENABLED_COMPRESS]

Some considerations:

  • Looks like lumberjack has a bit slower development pace now indeed. But it is still quite powerful and very popular solution, let's hope it will get some maintainers' or community attention soon. It's always possible to switch anyway.

  • I think it can be reasonable to move --log and --dbg inside of new log flags group. Having something like this looks more consistent for me:

    log:
          --log.enabled              enable logging [$CRONN_LOG_ENABLED]
          --log.debug                debug mode [$CRONN_LOG_DEBUG]
          --log.filename=            file to write logs to. Log to stdout if not specified [$CRONN_LOG_FILENAME]
          ...
    

    But I feel like such decision is out of the scope of the current pull request, can be done in some next PR easily.

  • I decided to make a single file log, just as usual cron does, for example. I see a lot of questions for having separate log files per job: log file name, directory structure, separate or common rotation. Potentially it can be done, but the scope is a lot bigger and the profit is not very understandable.

  • It looks to me that prefixing each output line is definitely possible, but not very easy thing to do with the current logger, because it doesn't have a concept of "child" loggers and custom prefixes for them (please correct me if I'm wrong).

    2020/07/26 16:48:52 INFO  executing: "ls -la"
    total 17576
    drwxr-xr-x  19 egor  staff      608 Jul 26 16:48 .
    drwxr-xr-x  58 egor  staff     1856 Jul 26 14:30 ..
    drwxr-xr-x  11 egor  staff      352 Jul 26 16:48 .git
    drwxr-xr-x   3 egor  staff       96 Jul 26 14:30 .github
    -rw-r--r--   1 egor  staff      273 Jul 26 14:30 .gitignore
    -rw-r--r--   1 egor  staff     1108 Jul 26 14:31 .golangci.yml
    -rw-r--r--   1 egor  staff      650 Jul 26 14:40 Dockerfile
    ...
    2020/07/26 16:48:52 INFO  completed ls -la
    

    I think current output maybe not ideal, but still a good start for future enhancements.

@umputun
Copy link
Owner

umputun commented Jul 26, 2020

Thx!

I think it can be reasonable to move --log and --dbg inside of new log flags group

makes sense

I decided to make a single file log, just as usual cron does

Fine with me. btw, looks like lumberjack has some issue with dynamically created logs (leaking goroutine on Close), so this decision is justified.

It looks to me that prefixing each output line is definitely possible, but not very easy thing to do with the current logger,

I think it is really easy to do if you wrap with your prefixer implementation of io.Writer directly in executeCommand

A few more things missing:

  • Will be nice to add info about this feature to readme and update --help output as well
  • Some test(s), probably in main_test.go. We don't need to test the functionality of lumberjack on our level, but integration testing will be good to have

@flexoid
Copy link
Contributor Author

flexoid commented Jul 27, 2020

@umputun what do you see as a prefix?
There is a command, which potentially can be quite long for a prefix.

I also see EntryID number inside robfig/cron, which is used in such output:

first: 2020-07-27T20:45:00+03:00, "ls -la ." (1) <- THIS ONE

It's not so straightforward how to get it in executeCommand, probably except for setting it to a new field of crontab.JobSpec inside of schedule right after getting an id.

@umputun
Copy link
Owner

umputun commented Jul 27, 2020

what do you see as a prefix?

I think we can have the command as a prefix limited by some reasonable maxlen (16?), i.e. {my command} log line blah

It's not so straightforward how to get it in executeCommand

In this case, you already have the command, so nothing new should be passed in

@flexoid flexoid force-pushed the rotated-logs-support branch from 3d380dc to 8b4138c Compare July 27, 2020 20:01
@flexoid
Copy link
Contributor Author

flexoid commented Jul 27, 2020

Now it's like this

2020/07/27 23:02:08 INFO  executing: "ls -la"
{ls -la} total 17600
{ls -la} drwxr-xr-x  20 egor  staff      640 Jul 27 22:25 .
{ls -la} drwxr-xr-x  58 egor  staff     1856 Jul 26 14:30 ..
{ls -la} drwxr-xr-x  11 egor  staff      352 Jul 27 23:01 .git
{ls -la} drwxr-xr-x   3 egor  staff       96 Jul 26 14:30 .github
{ls -la} -rw-r--r--   1 egor  staff      273 Jul 26 14:30 .gitignore
{ls -la} -rw-r--r--   1 egor  staff     1108 Jul 26 14:31 .golangci.yml
{ls -la} -rw-r--r--   1 egor  staff      650 Jul 26 14:40 Dockerfile
...
2020/07/27 23:02:08 INFO  completed ls -la
2020/07/27 23:02:08 INFO  next: 2020-07-27T23:02:13+03:00, "ls -la"
2020/07/27 23:07:26 INFO  executing: "ls -la /Users/egor/Sandbox/cronn"
{ls -la /Users/eg...} total 17600
{ls -la /Users/eg...} drwxr-xr-x  20 egor  staff      640 Jul 27 22:25 .
{ls -la /Users/eg...} drwxr-xr-x  58 egor  staff     1856 Jul 26 14:30 ..
{ls -la /Users/eg...} drwxr-xr-x  11 egor  staff      352 Jul 27 23:07 .git
{ls -la /Users/eg...} drwxr-xr-x   3 egor  staff       96 Jul 26 14:30 .github
{ls -la /Users/eg...} -rw-r--r--   1 egor  staff      273 Jul 26 14:30 .gitignore
{ls -la /Users/eg...} -rw-r--r--   1 egor  staff     1108 Jul 26 14:31 .golangci.yml
{ls -la /Users/eg...} -rw-r--r--   1 egor  staff      650 Jul 26 14:40 Dockerfile
...
2020/07/27 23:07:26 INFO  completed ls -la /Users/egor/Sandbox/cronn

I also added some tests, updated README and moved arguments under "log" group.

@umputun
Copy link
Owner

umputun commented Jul 27, 2020

yep, exactly what I meant

return logPrefixer
}

func (p *LogPrefixer) Write(data []byte) (int, error) {
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

do we really need all of this? How about this:

if len(data) >0 {
 p.Write(p.prefix)
 _, err := p.Write(data)
 return len(data), err
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But it will only prefix only first line of the command output.

Copy link
Contributor Author

@flexoid flexoid Jul 27, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would probably work if command produces output line by line, means internally calling Write for every line. Which is not the case even for ls -l, just tried.

2020/07/28 02:05:05 INFO  executing: "ls -l"
{ls -l} total 17576
-rw-r--r--  1 egor  staff      650 Jul 26 14:40 Dockerfile
-rw-r--r--  1 egor  staff     1842 Jul 26 14:32 Dockerfile.artifacts
-rw-r--r--  1 egor  staff     1064 Jul 26 14:30 LICENSE
...
2020/07/28 02:05:05 INFO  completed ls -

So all these complications are to prefix each line, no matter how many of them are contained in one data portion.

Copy link
Owner

@umputun umputun left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@umputun umputun merged commit 1fb0977 into umputun:master Jul 28, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants