Merge pull request #390 from NextTurn/line

Stop buffering stdout/stderr
pull/393/head
Oleg Nenashev 2020-01-31 22:49:26 +01:00 committed by GitHub
commit a1df4472a5
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 92 additions and 182 deletions

View File

@ -25,7 +25,7 @@ namespace winsw
public abstract class LogHandler public abstract class LogHandler
{ {
// ReSharper disable once InconsistentNaming // ReSharper disable once InconsistentNaming
public abstract void log(Stream outputStream, Stream errorStream); public abstract void log(StreamReader outputReader, StreamReader errorReader);
/// <summary> /// <summary>
/// Error and information about logging should be reported here. /// Error and information about logging should be reported here.
@ -37,21 +37,16 @@ namespace winsw
/// <summary> /// <summary>
/// Convenience method to copy stuff from StreamReader to StreamWriter /// Convenience method to copy stuff from StreamReader to StreamWriter
/// </summary> /// </summary>
protected void CopyStream(Stream i, Stream o) protected void CopyStream(StreamReader reader, StreamWriter writer)
{ {
byte[] buf = new byte[1024]; string? line;
while (true) while ((line = reader.ReadLine()) != null)
{ {
int sz = i.Read(buf, 0, buf.Length); writer.WriteLine(line);
if (sz == 0)
break;
o.Write(buf, 0, sz);
o.Flush();
} }
i.Close(); reader.Dispose();
o.Close(); writer.Dispose();
} }
/// <summary> /// <summary>
@ -90,6 +85,8 @@ namespace winsw
ErrFileDisabled = errFileDisabled; ErrFileDisabled = errFileDisabled;
ErrFilePattern = errFilePattern; ErrFilePattern = errFilePattern;
} }
protected StreamWriter CreateWriter(FileStream stream) => new StreamWriter(stream) { AutoFlush = true };
} }
public abstract class SimpleLogAppender : AbstractFileLogAppender public abstract class SimpleLogAppender : AbstractFileLogAppender
@ -106,13 +103,13 @@ namespace winsw
ErrorLogFileName = BaseLogFileName + ".err.log"; ErrorLogFileName = BaseLogFileName + ".err.log";
} }
public override void log(Stream outputStream, Stream errorStream) public override void log(StreamReader outputReader, StreamReader errorReader)
{ {
if (!OutFileDisabled) if (!OutFileDisabled)
new Thread(() => CopyStream(outputStream, new FileStream(OutputLogFileName, FileMode))).Start(); new Thread(() => CopyStream(outputReader, CreateWriter(new FileStream(OutputLogFileName, FileMode)))).Start();
if (!ErrFileDisabled) if (!ErrFileDisabled)
new Thread(() => CopyStream(errorStream, new FileStream(ErrorLogFileName, FileMode))).Start(); new Thread(() => CopyStream(errorReader, CreateWriter(new FileStream(ErrorLogFileName, FileMode)))).Start();
} }
} }
@ -137,10 +134,10 @@ namespace winsw
/// </summary> /// </summary>
public class IgnoreLogAppender : LogHandler public class IgnoreLogAppender : LogHandler
{ {
public override void log(Stream outputStream, Stream errorStream) public override void log(StreamReader outputReader, StreamReader errorReader)
{ {
new Thread(() => CopyStream(outputStream, Stream.Null)).Start(); new Thread(() => CopyStream(outputReader, StreamWriter.Null)).Start();
new Thread(() => CopyStream(errorStream, Stream.Null)).Start(); new Thread(() => CopyStream(errorReader, StreamWriter.Null)).Start();
} }
} }
@ -156,76 +153,38 @@ namespace winsw
Period = period; Period = period;
} }
public override void log(Stream outputStream, Stream errorStream) public override void log(StreamReader outputReader, StreamReader errorReader)
{ {
if (!OutFileDisabled) if (!OutFileDisabled)
new Thread(() => CopyStreamWithDateRotation(outputStream, OutFilePattern)).Start(); new Thread(() => CopyStreamWithDateRotation(outputReader, OutFilePattern)).Start();
if (!ErrFileDisabled) if (!ErrFileDisabled)
new Thread(() => CopyStreamWithDateRotation(errorStream, ErrFilePattern)).Start(); new Thread(() => CopyStreamWithDateRotation(errorReader, ErrFilePattern)).Start();
} }
/// <summary> /// <summary>
/// Works like the CopyStream method but does a log rotation based on time. /// Works like the CopyStream method but does a log rotation based on time.
/// </summary> /// </summary>
private void CopyStreamWithDateRotation(Stream data, string ext) private void CopyStreamWithDateRotation(StreamReader reader, string ext)
{ {
PeriodicRollingCalendar periodicRollingCalendar = new PeriodicRollingCalendar(Pattern, Period); PeriodicRollingCalendar periodicRollingCalendar = new PeriodicRollingCalendar(Pattern, Period);
periodicRollingCalendar.init(); periodicRollingCalendar.init();
byte[] buf = new byte[1024]; StreamWriter writer = CreateWriter(new FileStream(BaseLogFileName + "_" + periodicRollingCalendar.format + ext, FileMode.Append));
FileStream w = new FileStream(BaseLogFileName + "_" + periodicRollingCalendar.format + ext, FileMode.Append); string? line;
while (true) while ((line = reader.ReadLine()) != null)
{ {
int len = data.Read(buf, 0, buf.Length);
if (len == 0)
break; // EOF
if (periodicRollingCalendar.shouldRoll) if (periodicRollingCalendar.shouldRoll)
{ {
// rotate at the line boundary writer.Dispose();
int offset = 0; writer = CreateWriter(new FileStream(BaseLogFileName + "_" + periodicRollingCalendar.format + ext, FileMode.Create));
bool rolled = false;
for (int i = 0; i < len; i++)
{
if (buf[i] == 0x0A)
{
// at the line boundary.
// time to rotate.
w.Write(buf, offset, i + 1);
w.Close();
offset = i + 1;
// create a new file and write everything to the new file.
w = new FileStream(BaseLogFileName + "_" + periodicRollingCalendar.format + ext, FileMode.Create);
rolled = true;
if (offset < len)
{
w.Write(buf, offset, len - offset);
break;
}
}
}
if (!rolled)
{
// we didn't roll - most likely as we didnt find a line boundary, so we should log what we read and roll anyway.
w.Write(buf, 0, len);
w.Close();
w = new FileStream(BaseLogFileName + "_" + periodicRollingCalendar.format + ext, FileMode.Create);
}
}
else
{
// typical case. write the whole thing into the current file
w.Write(buf, 0, len);
} }
w.Flush(); writer.WriteLine(line);
} }
data.Close(); reader.Dispose();
w.Close(); writer.Dispose();
} }
} }
@ -254,86 +213,63 @@ namespace winsw
public SizeBasedRollingLogAppender(string logDirectory, string baseName, bool outFileDisabled, bool errFileDisabled, string outFilePattern, string errFilePattern) public SizeBasedRollingLogAppender(string logDirectory, string baseName, bool outFileDisabled, bool errFileDisabled, string outFilePattern, string errFilePattern)
: this(logDirectory, baseName, outFileDisabled, errFileDisabled, outFilePattern, errFilePattern, DEFAULT_SIZE_THRESHOLD, DEFAULT_FILES_TO_KEEP) { } : this(logDirectory, baseName, outFileDisabled, errFileDisabled, outFilePattern, errFilePattern, DEFAULT_SIZE_THRESHOLD, DEFAULT_FILES_TO_KEEP) { }
public override void log(Stream outputStream, Stream errorStream) public override void log(StreamReader outputReader, StreamReader errorReader)
{ {
if (!OutFileDisabled) if (!OutFileDisabled)
new Thread(() => CopyStreamWithRotation(outputStream, OutFilePattern)).Start(); new Thread(() => CopyStreamWithRotation(outputReader, OutFilePattern)).Start();
if (!ErrFileDisabled) if (!ErrFileDisabled)
new Thread(() => CopyStreamWithRotation(errorStream, ErrFilePattern)).Start(); new Thread(() => CopyStreamWithRotation(errorReader, ErrFilePattern)).Start();
} }
/// <summary> /// <summary>
/// Works like the CopyStream method but does a log rotation. /// Works like the CopyStream method but does a log rotation.
/// </summary> /// </summary>
private void CopyStreamWithRotation(Stream data, string ext) private void CopyStreamWithRotation(StreamReader reader, string ext)
{ {
byte[] buf = new byte[1024]; StreamWriter writer = CreateWriter(new FileStream(BaseLogFileName + ext, FileMode.Append));
FileStream w = new FileStream(BaseLogFileName + ext, FileMode.Append); long fileLength = new FileInfo(BaseLogFileName + ext).Length;
long sz = new FileInfo(BaseLogFileName + ext).Length;
while (true) string? line;
while ((line = reader.ReadLine()) != null)
{ {
int len = data.Read(buf, 0, buf.Length); int lengthToWrite = (line.Length + Environment.NewLine.Length) * sizeof(char);
if (len == 0) if (fileLength + lengthToWrite > SizeTheshold)
break; // EOF {
writer.Dispose();
if (sz + len < SizeTheshold) try
{
// typical case. write the whole thing into the current file
w.Write(buf, 0, len);
sz += len;
}
else
{
// rotate at the line boundary
int s = 0;
for (int i = 0; i < len; i++)
{ {
if (buf[i] != 0x0A) for (int j = FilesToKeep; j >= 1; j--)
continue;
if (sz + i < SizeTheshold)
continue;
// at the line boundary and exceeded the rotation unit.
// time to rotate.
w.Write(buf, s, i + 1);
w.Close();
s = i + 1;
try
{ {
for (int j = FilesToKeep; j >= 1; j--) string dst = BaseLogFileName + "." + (j - 1) + ext;
{ string src = BaseLogFileName + "." + (j - 2) + ext;
string dst = BaseLogFileName + "." + (j - 1) + ext; if (File.Exists(dst))
string src = BaseLogFileName + "." + (j - 2) + ext; File.Delete(dst);
if (File.Exists(dst))
File.Delete(dst);
if (File.Exists(src)) if (File.Exists(src))
File.Move(src, dst); File.Move(src, dst);
}
File.Move(BaseLogFileName + ext, BaseLogFileName + ".0" + ext);
}
catch (IOException e)
{
EventLogger.LogEvent("Failed to rotate log: " + e.Message);
} }
// even if the log rotation fails, create a new one, or else File.Move(BaseLogFileName + ext, BaseLogFileName + ".0" + ext);
// we'll infinitely try to rotate.
w = new FileStream(BaseLogFileName + ext, FileMode.Create);
sz = new FileInfo(BaseLogFileName + ext).Length;
} }
catch (IOException e)
{
EventLogger.LogEvent("Failed to rotate log: " + e.Message);
}
// even if the log rotation fails, create a new one, or else
// we'll infinitely try to rotate.
writer = CreateWriter(new FileStream(BaseLogFileName + ext, FileMode.Create));
fileLength = new FileInfo(BaseLogFileName + ext).Length;
} }
w.Flush(); writer.WriteLine(line);
fileLength += lengthToWrite;
} }
data.Close(); reader.Dispose();
w.Close(); writer.Dispose();
} }
} }
@ -347,7 +283,7 @@ namespace winsw
{ {
} }
public override void log(Stream outputStream, Stream errorStream) public override void log(StreamReader outputReader, StreamReader errorReader)
{ {
if (!OutFileDisabled) if (!OutFileDisabled)
CopyFile(OutputLogFileName, OutputLogFileName + ".old"); CopyFile(OutputLogFileName, OutputLogFileName + ".old");
@ -355,7 +291,7 @@ namespace winsw
if (!ErrFileDisabled) if (!ErrFileDisabled)
CopyFile(ErrorLogFileName, ErrorLogFileName + ".old"); CopyFile(ErrorLogFileName, ErrorLogFileName + ".old");
base.log(outputStream, errorStream); base.log(outputReader, errorReader);
} }
} }
@ -389,28 +325,26 @@ namespace winsw
ZipDateFormat = zipdateformat; ZipDateFormat = zipdateformat;
} }
public override void log(Stream outputStream, Stream errorStream) public override void log(StreamReader outputReader, StreamReader errorReader)
{ {
if (!OutFileDisabled) if (!OutFileDisabled)
new Thread(() => CopyStreamWithRotation(outputStream, OutFilePattern)).Start(); new Thread(() => CopyStreamWithRotation(outputReader, OutFilePattern)).Start();
if (!ErrFileDisabled) if (!ErrFileDisabled)
new Thread(() => CopyStreamWithRotation(errorStream, ErrFilePattern)).Start(); new Thread(() => CopyStreamWithRotation(errorReader, ErrFilePattern)).Start();
} }
private void CopyStreamWithRotation(Stream data, string extension) private void CopyStreamWithRotation(StreamReader reader, string extension)
{ {
// lock required as the timer thread and the thread that will write to the stream could try and access the file stream at the same time // lock required as the timer thread and the thread that will write to the stream could try and access the file stream at the same time
var fileLock = new object(); var fileLock = new object();
var buf = new byte[1024];
var baseDirectory = Path.GetDirectoryName(BaseLogFileName)!; var baseDirectory = Path.GetDirectoryName(BaseLogFileName)!;
var baseFileName = Path.GetFileName(BaseLogFileName); var baseFileName = Path.GetFileName(BaseLogFileName);
var logFile = BaseLogFileName + extension; var logFile = BaseLogFileName + extension;
var w = new FileStream(logFile, FileMode.Append); var writer = CreateWriter(new FileStream(logFile, FileMode.Append));
var sz = new FileInfo(logFile).Length; var fileLength = new FileInfo(logFile).Length;
// We auto roll at time is configured then we need to create a timer and wait until time is elasped and roll the file over // We auto roll at time is configured then we need to create a timer and wait until time is elasped and roll the file over
if (AutoRollAtTime is TimeSpan autoRollAtTime) if (AutoRollAtTime is TimeSpan autoRollAtTime)
@ -425,15 +359,15 @@ namespace winsw
timer.Stop(); timer.Stop();
lock (fileLock) lock (fileLock)
{ {
w.Close(); writer.Dispose();
var now = DateTime.Now.AddDays(-1); var now = DateTime.Now.AddDays(-1);
var nextFileNumber = GetNextFileNumber(extension, baseDirectory, baseFileName, now); var nextFileNumber = GetNextFileNumber(extension, baseDirectory, baseFileName, now);
var nextFileName = Path.Combine(baseDirectory, string.Format("{0}.{1}.#{2:D4}{3}", baseFileName, now.ToString(FilePattern), nextFileNumber, extension)); var nextFileName = Path.Combine(baseDirectory, string.Format("{0}.{1}.#{2:D4}{3}", baseFileName, now.ToString(FilePattern), nextFileNumber, extension));
File.Move(logFile, nextFileName); File.Move(logFile, nextFileName);
w = new FileStream(logFile, FileMode.Create); writer = CreateWriter(new FileStream(logFile, FileMode.Create));
sz = new FileInfo(logFile).Length; fileLength = new FileInfo(logFile).Length;
} }
// Next day so check if file can be zipped // Next day so check if file can be zipped
@ -453,53 +387,28 @@ namespace winsw
timer.Start(); timer.Start();
} }
while (true) string? line;
while ((line = reader.ReadLine()) != null)
{ {
var len = data.Read(buf, 0, buf.Length);
if (len == 0)
break; // EOF
lock (fileLock) lock (fileLock)
{ {
if (sz + len < SizeTheshold) int lengthToWrite = (line.Length + Environment.NewLine.Length) * sizeof(char);
{ if (fileLength + lengthToWrite > SizeTheshold)
// typical case. write the whole thing into the current file
w.Write(buf, 0, len);
sz += len;
}
else
{ {
try try
{ {
// rotate at the line boundary // rotate file
int s = 0; var now = DateTime.Now;
for (int i = 0; i < len; i++) var nextFileNumber = GetNextFileNumber(extension, baseDirectory, baseFileName, now);
{ var nextFileName =
if (buf[i] != 0x0A) Path.Combine(baseDirectory,
continue; string.Format("{0}.{1}.#{2:D4}{3}", baseFileName, now.ToString(FilePattern), nextFileNumber, extension));
File.Move(logFile, nextFileName);
if (sz + i < SizeTheshold) // even if the log rotation fails, create a new one, or else
continue; // we'll infinitely try to rotate.
writer = CreateWriter(new FileStream(logFile, FileMode.Create));
// at the line boundary and exceeded the rotation unit. fileLength = new FileInfo(logFile).Length;
// time to rotate.
w.Write(buf, s, i + 1);
w.Close();
s = i + 1;
// rotate file
var now = DateTime.Now;
var nextFileNumber = GetNextFileNumber(extension, baseDirectory, baseFileName, now);
var nextFileName =
Path.Combine(baseDirectory,
string.Format("{0}.{1}.#{2:D4}{3}", baseFileName, now.ToString(FilePattern), nextFileNumber, extension));
File.Move(logFile, nextFileName);
// even if the log rotation fails, create a new one, or else
// we'll infinitely try to rotate.
w = new FileStream(logFile, FileMode.Create);
sz = new FileInfo(logFile).Length;
}
} }
catch (Exception e) catch (Exception e)
{ {
@ -507,12 +416,13 @@ namespace winsw
} }
} }
w.Flush(); writer.WriteLine(line);
fileLength += lengthToWrite;
} }
} }
data.Close(); reader.Dispose();
w.Close(); writer.Dispose();
} }
private void ZipFiles(string directory, string fileExtension, string zipFileBaseName) private void ZipFiles(string directory, string fileExtension, string zipFileBaseName)

View File

@ -175,7 +175,7 @@ namespace winsw.Util
if (logHandler != null) if (logHandler != null)
{ {
Logger.Debug("Forwarding logs of the process " + processToStart + " to " + logHandler); Logger.Debug("Forwarding logs of the process " + processToStart + " to " + logHandler);
logHandler.log(processToStart.StandardOutput.BaseStream, processToStart.StandardError.BaseStream); logHandler.log(processToStart.StandardOutput, processToStart.StandardError);
} }
// monitor the completion of the process // monitor the completion of the process