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

Optionally log command output #915

Merged
merged 1 commit into from Jul 12, 2019

Conversation

Projects
None yet
4 participants
@joeldrapper
Copy link
Contributor

commented Jun 28, 2019

Optionally log command output to Shipit.task_logger with context on the current repo / deployment.

Because an output chunk can contain more or less than one line, we first buffer the output into whole lines and then format it with the current context before sending it on to the configured task logger.

@joeldrapper joeldrapper self-assigned this Jun 28, 2019

@joeldrapper joeldrapper force-pushed the log_command_output branch from e86dd8c to faaecbb Jun 28, 2019

@joeldrapper

This comment has been minimized.

Copy link
Contributor Author

commented Jun 28, 2019

@DazWorrall @byroot I’m not sure how I should attach more context here, such as the repo / deployment id.

Also, @DazWorrall suggested this output should be optional, but I’m not sure how best to do that. Are there any other configurable options implemented that I can look at?

@casperisfine

This comment has been minimized.

Copy link
Contributor

commented Jun 28, 2019

@joeldrapper I think for both of your question, the solution is the same.

Doing this logging in Command is not the best place because it's a quite low level class which doesn't know much about what it's doing.

Ultimately the output is registered here:

def write(text)
chunks.create!(text: text)
end

That's a much better hook point in my opinion since your are inside the Task, so you know what stack & task you belong to.

As for making it opt-in / configurable, I'd say:

def write(text)
  Shipit.task_logger.info(text)
  chunks.create!(text: text)
end

This way it's a config people can set in application.rb or config/environments/*.rb. It should default to Logger.new(nil).

@joeldrapper

This comment has been minimized.

Copy link
Contributor Author

commented Jun 28, 2019

I originally looked at implementing this as a callback on OutputChunks. @DazWorrall suggested that these should be written by the actual job process and not any web process for a few reasons:

  1. the chunks aren’t line buffered, which splunk cares about
  2. the web processes will interleave their own output
  3. if we echo it async we lose ordering guarantees

I guess we'd have the same problems using Task#write.

I love the idea of using a null logger by default. 👌

@casperisfine

This comment has been minimized.

Copy link
Contributor

commented Jun 28, 2019

these should be written by the actual job process and not any web process

Task#write is only called from jobs, never from web workers.

As for the buffering etc concerns, that is a deployment concern. If you need log buffering, then simply set Shipit.task_logger to some buffered logger implementation.

@DazWorrall

This comment has been minimized.

Copy link
Member

commented Jul 1, 2019

@casperisfine I was concerned about line buffering - chunks are (afaics) byte streams, and so could contain a partial line, or multiple lines. I didn't expect piping chunks straight to the logger would result in very legible output.

@casperisfine

This comment has been minimized.

Copy link
Contributor

commented Jul 1, 2019

chunks are (afaics) byte streams, and so could contain a partial line, or multiple lines

Yes they are. And since Shipit use a PTY, many command will write partial lines, clear the line etc.

@joeldrapper

This comment has been minimized.

Copy link
Contributor Author

commented Jul 3, 2019

Can we just make a logger that handles line buffering?

@casperisfine

This comment has been minimized.

Copy link
Contributor

commented Jul 3, 2019

Yes probably, and it's likely the best solution.

@joeldrapper

This comment has been minimized.

Copy link
Contributor Author

commented Jul 3, 2019

I don't think it's obvious that Shipit.task_logger itself should line buffered, so I wonder if we should decorate it from Shipit::Task, i.e.

def write(text)
  task_logger.info(text)
  chunks.create!(text: text)
end

private

def task_logger
  @task_logger ||= LineBufferedLogger.new(Shipit.task_logger)
end
@casperisfine

This comment has been minimized.

Copy link
Contributor

commented Jul 3, 2019

I'm fine with that.

@joeldrapper joeldrapper force-pushed the log_command_output branch from faaecbb to c33bdf6 Jul 8, 2019

@joeldrapper joeldrapper changed the title Write command output to stdout Log command output Jul 8, 2019

@joeldrapper joeldrapper changed the title Log command output Optionally log command output Jul 8, 2019

@joeldrapper joeldrapper force-pushed the log_command_output branch 5 times, most recently from 3252ccf to 8142800 Jul 8, 2019

Show resolved Hide resolved app/models/shipit/task.rb Outdated

@joeldrapper joeldrapper force-pushed the log_command_output branch 6 times, most recently from 25a1ffa to 87543f1 Jul 8, 2019

@joeldrapper joeldrapper marked this pull request as ready for review Jul 8, 2019

@joeldrapper joeldrapper requested review from casperisfine and DazWorrall Jul 8, 2019

@joeldrapper joeldrapper requested a review from itsAmr Jul 8, 2019

@joeldrapper joeldrapper force-pushed the log_command_output branch from 87543f1 to 4bd1e2b Jul 8, 2019

@itsAmr
Copy link

left a comment

LineBuffer code is 👌👌

Show resolved Hide resolved lib/shipit/line_buffer.rb Outdated
Show resolved Hide resolved lib/shipit/line_buffer.rb Outdated
Show resolved Hide resolved lib/shipit/line_buffer.rb
Show resolved Hide resolved lib/shipit/line_buffer.rb Outdated
Show resolved Hide resolved lib/shipit/line_buffer.rb Outdated

@joeldrapper joeldrapper force-pushed the log_command_output branch from 9bb052a to 6ba4cc0 Jul 10, 2019

@joeldrapper joeldrapper requested review from casperisfine and DazWorrall Jul 11, 2019

@DazWorrall
Copy link
Member

left a comment

:shipit:

Optionally log command output
Optionally configure a task logger which receives command output with 
context about the task and repository.

@joeldrapper joeldrapper force-pushed the log_command_output branch from 0574816 to 38f6c94 Jul 11, 2019

@joeldrapper joeldrapper merged commit e85eb2b into master Jul 12, 2019

3 checks passed

CLA Contributor License Agreement (CLA) status
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details
continuous-integration/travis-ci/push The Travis CI build passed
Details

@joeldrapper joeldrapper deleted the log_command_output branch Jul 12, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.