PB-8293 : Implement a new log writer which flushes the logs in every 30 seconds (for real time logs) #397
Conversation
…30 seconds (for real time logs) Signed-off-by: Kesavan Thiruvenkadasamy <[email protected]>
px-kesavan
requested review from
lalat-das,
prashanthpx,
siva-portworx,
vikasit12,
pallav-px and
vsundarraj-px
| } | ||
|
|
||
| func (lw *logWriter) Write(p []byte) (n int, err error) { | ||
| lw.mu.Lock() |
There was a problem hiding this comment.
Why we need this mutex. What is the scenario when write will be called from two parallel path.
Isn't multi writer already takes care of writing to two file descriptor in parallel with synchronization on.
There was a problem hiding this comment.
Even though we create two separate objects by calling newLogWriter for stderr and stdout, there is a chance that write can be called by multiple goroutines at the same time if the snapshot create command generates output quickly. It's unlikely to happen, but I have added a mutex for extra integrity of the output data
| now := time.Now() | ||
| // log if the interval has passed since the last log | ||
| // this is to avoid bloating the logs | ||
| if now.Sub(lw.lastLogTime) >= lw.interval { |
There was a problem hiding this comment.
What will be the behavior if backup gets completed with 30 sec. Nothing will be written ? Say some error in the command line happens and command is done. I am confused about the lastLogTime's value when for the first time the write call is invoked ? Any default value need to be assigned? or is it because it will be zero and So now - 0 already takes care of it?
There was a problem hiding this comment.
First write will not wait for 30secs, it will be written as when it comes.
To explain on the lastLogTime value for the first time will be 0 time format.
if block basically does (time.Now() - lastLogTime ) > 30 sec, Which will succeed .
| // log if the interval has passed since the last log | ||
| // this is to avoid bloating the logs | ||
| if now.Sub(lw.lastLogTime) >= lw.interval { | ||
| lw.logger.Println(string(p), time.Now()) |
There was a problem hiding this comment.
Please add a test case showcasing failure of kopia command if it can happen within 30 sec and log appears as expected then we are good.
There was a problem hiding this comment.
Please refer the ticket, have attached for the same
|
|
||
| // Create multi-writers to stream output to both buffer and CLI | ||
| stdoutWriter := io.MultiWriter(b.outBuf, newLogWriter(log.New(os.Stdout, "", 0), commandExecLogInterval)) | ||
| stderrWriter := io.MultiWriter(b.errBuf, newLogWriter(log.New(os.Stderr, "", 0), commandExecLogInterval)) |
There was a problem hiding this comment.
Not doubting the golang primitives here but it would be good if we can check outBuf errBuf are working as expected by checking summary response also populated as expected. A unit test around that would be great.
There was a problem hiding this comment.
Not doubting , but still doubting :) . Have attached the logs for the same in the ticket. Thanks
…30 seconds (for real time logs)
What this PR does / why we need it: Currently the output of kopia backup/restore command is flushed in to the pod logs only after the cmd execution , so the user is not aware of the progress This PR Implements a new log writer which flushes the logs in every 30 seconds (for real time logs)
Which issue(s) this PR fixes (optional)
Closes # https://purestorage.atlassian.net/browse/PB-8293
Special notes for your reviewer:
Output for backup
Attached additional testing details with logs in the ticket https://purestorage.atlassian.net/browse/PB-8293