From cfc64d9b4e88696f92ffc85954fa2f829f00b116 Mon Sep 17 00:00:00 2001 From: tomer doron Date: Wed, 7 Aug 2019 14:34:17 -0700 Subject: [PATCH 1/2] add flush api to default stdout/stderr logger motivation: default logger may not flush the streams on crush, so need to make flushing moe explicit changes: * add a constructor argument to control flushing behaviour, default to "everytime" * add a "flush" method to allow user defined flush timing. this api is now internal but we could expose it if there is a need * add tests --- Sources/Logging/Logging.swift | 26 ++++++-- Tests/LoggingTests/LoggingTest+XCTest.swift | 1 + Tests/LoggingTests/LoggingTest.swift | 68 +++++++++++++++++++++ 3 files changed, 90 insertions(+), 5 deletions(-) diff --git a/Sources/Logging/Logging.swift b/Sources/Logging/Logging.swift index 32dfc035..51516e48 100644 --- a/Sources/Logging/Logging.swift +++ b/Sources/Logging/Logging.swift @@ -531,19 +531,35 @@ public struct MultiplexLogHandler: LogHandler { /// cross-thread interleaving of output. internal struct StdioOutputStream: TextOutputStream { internal let file: UnsafeMutablePointer + internal let flushMode: FlushMode internal func write(_ string: String) { string.withCString { ptr in - flockfile(file) + flockfile(self.file) defer { - funlockfile(file) + funlockfile(self.file) + } + _ = fputs(ptr, self.file) + if case .always = self.flushMode { + self.flush() } - _ = fputs(ptr, file) } } - internal static let stderr = StdioOutputStream(file: systemStderr) - internal static let stdout = StdioOutputStream(file: systemStdout) + /// Flush the underlying stream. + /// This has no effect when using the `.always` flush mode, which is the default + internal func flush() { + _ = fflush(self.file) + } + + internal static let stderr = StdioOutputStream(file: systemStderr, flushMode: .always) + internal static let stdout = StdioOutputStream(file: systemStdout, flushMode: .always) + + /// Defines the flushing strategy for the underlying stream. + internal enum FlushMode { + case undefined + case always + } } // Prevent name clashes diff --git a/Tests/LoggingTests/LoggingTest+XCTest.swift b/Tests/LoggingTests/LoggingTest+XCTest.swift index 1a4ee52d..77fb4ffd 100644 --- a/Tests/LoggingTests/LoggingTest+XCTest.swift +++ b/Tests/LoggingTests/LoggingTest+XCTest.swift @@ -42,6 +42,7 @@ extension LoggingTest { ("testLogLevelCases", testLogLevelCases), ("testLogLevelOrdering", testLogLevelOrdering), ("testStreamLogHandlerWritesToAStream", testStreamLogHandlerWritesToAStream), + ("testStdioOutputStreamFlush", testStdioOutputStreamFlush), ] } } diff --git a/Tests/LoggingTests/LoggingTest.swift b/Tests/LoggingTests/LoggingTest.swift index 7375e4e9..f2e2408b 100644 --- a/Tests/LoggingTests/LoggingTest.swift +++ b/Tests/LoggingTests/LoggingTest.swift @@ -14,6 +14,12 @@ @testable import Logging import XCTest +#if os(macOS) || os(iOS) || os(tvOS) || os(watchOS) +import Darwin +#else +import Glibc +#endif + class LoggingTest: XCTestCase { func testAutoclosure() throws { // bootstrap with our test logging impl @@ -444,4 +450,66 @@ class LoggingTest: XCTestCase { XCTAssertTrue(messageSucceeded ?? false) XCTAssertEqual(interceptStream.strings.count, 1) } + + func testStdioOutputStreamFlush() { + // flush on every statement + self.testStdioOutputStreamFlush { writeFD, readFD, readBuffer in + let logStream = StdioOutputStream(file: writeFD, flushMode: .always) + LoggingSystem.bootstrapInternal { StreamLogHandler(label: $0, stream: logStream) } + Logger(label: "test").critical("test") + + let size = read(readFD, readBuffer, 256) + XCTAssertGreaterThan(size, -1, "expected flush") + + logStream.flush() + let size2 = read(readFD, readBuffer, 256) + XCTAssertEqual(size2, -1, "expected no flush") + } + // default flushing + self.testStdioOutputStreamFlush { writeFD, readFD, readBuffer in + let logStream = StdioOutputStream(file: writeFD, flushMode: .undefined) + LoggingSystem.bootstrapInternal { StreamLogHandler(label: $0, stream: logStream) } + Logger(label: "test").critical("test") + + let size = read(readFD, readBuffer, 256) + XCTAssertEqual(size, -1, "expected no flush") + + logStream.flush() + let size2 = read(readFD, readBuffer, 256) + XCTAssertGreaterThan(size2, -1, "expected flush") + } + } + + func testStdioOutputStreamFlush(_ body: (UnsafeMutablePointer, CInt, UnsafeMutablePointer) -> Void) { + var fds: [Int32] = [-1, -1] + fds.withUnsafeMutableBufferPointer { ptr in + let err = pipe(ptr.baseAddress!) + assert(err == 0, "pipe: \(err)") + } + + let writeFD = fdopen(fds[1], "w") + let writeBuffer = UnsafeMutablePointer.allocate(capacity: 256) + defer { + writeBuffer.deinitialize(count: 256) + writeBuffer.deallocate() + } + + var err = setvbuf(writeFD, writeBuffer, _IOFBF, 256) + assert(err == 0) + + let readFD = fds[0] + err = fcntl(readFD, F_SETFL, fcntl(readFD, F_GETFL) | O_NONBLOCK) + assert(err == 0) + + let readBuffer = UnsafeMutablePointer.allocate(capacity: 256) + defer { + readBuffer.deinitialize(count: 256) + readBuffer.deallocate() + } + + // the actual test + body(writeFD!, readFD, readBuffer) + + fds.forEach { close($0) } + } } From 68c9cbc0c4e656fedd24e24fb043f69dcb844016 Mon Sep 17 00:00:00 2001 From: tomer doron Date: Mon, 12 Aug 2019 16:35:44 -0700 Subject: [PATCH 2/2] fixup --- Tests/LoggingTests/LoggingTest.swift | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/Tests/LoggingTests/LoggingTest.swift b/Tests/LoggingTests/LoggingTest.swift index f2e2408b..295c9e21 100644 --- a/Tests/LoggingTests/LoggingTest.swift +++ b/Tests/LoggingTests/LoggingTest.swift @@ -453,7 +453,7 @@ class LoggingTest: XCTestCase { func testStdioOutputStreamFlush() { // flush on every statement - self.testStdioOutputStreamFlush { writeFD, readFD, readBuffer in + self.withWriteReadFDsAndReadBuffer { writeFD, readFD, readBuffer in let logStream = StdioOutputStream(file: writeFD, flushMode: .always) LoggingSystem.bootstrapInternal { StreamLogHandler(label: $0, stream: logStream) } Logger(label: "test").critical("test") @@ -466,7 +466,7 @@ class LoggingTest: XCTestCase { XCTAssertEqual(size2, -1, "expected no flush") } // default flushing - self.testStdioOutputStreamFlush { writeFD, readFD, readBuffer in + self.withWriteReadFDsAndReadBuffer { writeFD, readFD, readBuffer in let logStream = StdioOutputStream(file: writeFD, flushMode: .undefined) LoggingSystem.bootstrapInternal { StreamLogHandler(label: $0, stream: logStream) } Logger(label: "test").critical("test") @@ -480,11 +480,11 @@ class LoggingTest: XCTestCase { } } - func testStdioOutputStreamFlush(_ body: (UnsafeMutablePointer, CInt, UnsafeMutablePointer) -> Void) { + func withWriteReadFDsAndReadBuffer(_ body: (UnsafeMutablePointer, CInt, UnsafeMutablePointer) -> Void) { var fds: [Int32] = [-1, -1] fds.withUnsafeMutableBufferPointer { ptr in let err = pipe(ptr.baseAddress!) - assert(err == 0, "pipe: \(err)") + XCTAssertEqual(err, 0, "pipe faild \(err)") } let writeFD = fdopen(fds[1], "w") @@ -495,11 +495,11 @@ class LoggingTest: XCTestCase { } var err = setvbuf(writeFD, writeBuffer, _IOFBF, 256) - assert(err == 0) + XCTAssertEqual(err, 0, "setvbuf faild \(err)") let readFD = fds[0] err = fcntl(readFD, F_SETFL, fcntl(readFD, F_GETFL) | O_NONBLOCK) - assert(err == 0) + XCTAssertEqual(err, 0, "fcntl faild \(err)") let readBuffer = UnsafeMutablePointer.allocate(capacity: 256) defer {