Skip to content

Commit

Permalink
Changed the log collector to use a pipe and added a unit test
Browse files Browse the repository at this point in the history
  • Loading branch information
mbruin-NR committed Oct 23, 2024
1 parent 3865382 commit 3d1ca9c
Show file tree
Hide file tree
Showing 3 changed files with 145 additions and 80 deletions.
1 change: 0 additions & 1 deletion Agent/Utilities/NRAutoLogCollector.h
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,5 @@

+ (void) redirectStandardOutputAndError;
+ (void) restoreStandardOutputAndError;
+ (void) readAndParseLogFile;

@end
137 changes: 58 additions & 79 deletions Agent/Utilities/NRAutoLogCollector.m
Original file line number Diff line number Diff line change
Expand Up @@ -11,81 +11,84 @@

int saved_stdout;
int saved_stderr;
FILE* fileDescriptor;
int stdoutPipe[2];
int stderrPipe[2];

@interface NRAutoLogCollector()

@end

@implementation NRAutoLogCollector

+ (NSURL *) logFileURL {
NSFileManager *fileManager = [NSFileManager defaultManager];
NSArray<NSURL *> *urls = [fileManager URLsForDirectory:NSDocumentDirectory inDomains:NSUserDomainMask];
NSURL *logsDirectory = [urls firstObject];
return [logsDirectory URLByAppendingPathComponent:@"agent.log"];
}

+ (void) clearLogFile {
[[NSFileManager defaultManager] removeItemAtURL:[NRAutoLogCollector logFileURL] error:nil];

[NRAutoLogCollector redirectStandardOutputAndError];
}

+ (void) redirectStandardOutputAndError {
// Save the original stdout file descriptor
// Create pipes for stdout and stderr
if (pipe(stdoutPipe) == -1 || pipe(stderrPipe) == -1) {
return;
}

// Save the original stdout and stderr file descriptors
saved_stdout = dup(fileno(stdout));
saved_stderr = dup(fileno(stderr));
if (saved_stdout == -1 || saved_stderr == -1) {
close(stdoutPipe[0]);
close(stdoutPipe[1]);
close(stderrPipe[0]);
close(stderrPipe[1]);
return;
}

// Redirect stdout to the file
freopen([[NRAutoLogCollector logFileURL].path cStringUsingEncoding:NSUTF8StringEncoding], "a+", stdout);
fileDescriptor = freopen([[NRAutoLogCollector logFileURL].path cStringUsingEncoding:NSUTF8StringEncoding], "a+", stderr);

[NRAutoLogCollector monitorFile:[NRAutoLogCollector logFileURL].path];
// Redirect stdout and stderr to the write ends of the pipes
if (dup2(stdoutPipe[1], fileno(stdout)) == -1 || dup2(stderrPipe[1], fileno(stderr)) == -1) {
close(stdoutPipe[0]);
close(stdoutPipe[1]);
close(stderrPipe[0]);
close(stderrPipe[1]);
close(saved_stdout);
close(saved_stderr);
return;
}
close(stdoutPipe[1]); // Close the original write end of the stdout pipe
close(stderrPipe[1]); // Close the original write end of the stderr pipe

// Read from the pipes in background threads
dispatch_async(dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_BACKGROUND, 0), ^{
[NRAutoLogCollector readAndLog:stdoutPipe[0]];
});
dispatch_async(dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_BACKGROUND, 0), ^{
[NRAutoLogCollector readAndLog:stderrPipe[0]];
});

// Restore the original stdout and stderr when done
atexit_b(^{
[NRAutoLogCollector restoreStandardOutputAndError];
});
}

+ (void) readAndLog:(int) fd {
char buffer[2048];
ssize_t count;
while ((count = read(fd, buffer, sizeof(buffer) - 1)) > 0) {
buffer[count] = '\0'; // Null-terminate the string
NSString *output = [NSString stringWithUTF8String:buffer];
NSArray<NSString *> *newLogEntries = [output componentsSeparatedByString:@"\n\n"];

// Process each log entry
for (NSString *logEntry in newLogEntries) {
if ([logEntry length] > 0) {
[NRLogger log:[NRAutoLogCollector extractType:logEntry] withMessage:logEntry withTimestamp:[NRAutoLogCollector extractTimestamp:logEntry]];
}
}
}
close(fd);
}

+ (void) restoreStandardOutputAndError {
[NRAutoLogCollector readAndParseLogFile];

// Restore the original stdout
dup2(saved_stdout, fileno(stdout));
dup2(saved_stderr, fileno(stderr));
close(saved_stdout);
close(saved_stderr);
}

+ (void) readAndParseLogFile {
fflush(stdout);
fflush(stderr);
// Check if the file exists
if (![[NSFileManager defaultManager] fileExistsAtPath:[NRAutoLogCollector logFileURL].path]) {
return;
}

// Read the file content into an NSString
NSError *error = nil;
NSString *fileContents = [NSString stringWithContentsOfFile:[NRAutoLogCollector logFileURL].path
encoding:NSUTF8StringEncoding
error:&error];
[NRAutoLogCollector clearLogFile];

if (error) {
return;
} else if (fileContents.length == 0){
return;
}

// Split the file contents into individual log entries
NSArray<NSString *> *newLogEntries = [fileContents componentsSeparatedByString:@"\n\n"];

// Process each log entry
for (NSString *logEntry in newLogEntries) {
if ([logEntry length] > 0) {
[NRLogger log:[NRAutoLogCollector extractType:logEntry] withMessage:logEntry withTimestamp:[NRAutoLogCollector extractTimestamp:logEntry]];
}
}
}

+ (BOOL) isValidTimestamp:(NSString *) timestampString {
// Check if the timestamp string can be converted to a double
double timestamp = [timestampString doubleValue];
Expand Down Expand Up @@ -148,29 +151,5 @@ + (unsigned int) extractType:(NSString *) inputString {

return NRLogLevelNone;
}

+ (void) monitorFile:(NSString *) filePath {
// Create a dispatch queue for handling log file events
dispatch_queue_t queue = dispatch_queue_create("newrelic.log.monitor.queue", NULL);

// Create a dispatch source to monitor the file descriptor for writes
dispatch_source_t source = dispatch_source_create(DISPATCH_SOURCE_TYPE_VNODE, fileno(fileDescriptor), DISPATCH_VNODE_WRITE, queue);

// Set the event handler block
dispatch_source_set_event_handler(source, ^{
unsigned long flags = dispatch_source_get_data(source);
if (flags & DISPATCH_VNODE_WRITE) {
[NRAutoLogCollector readAndParseLogFile];
}
});

// Set the cancel handler block
dispatch_source_set_cancel_handler(source, ^{
close(fileno(fileDescriptor));
});

// Start monitoring
dispatch_resume(source);
}

@end
87 changes: 87 additions & 0 deletions Tests/Unit-Tests/NewRelicAgentTests/Uncategorized/NRLoggerTests.m
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,8 @@
#import "NRMAAppToken.h"
#import "NRMAHarvestController.h"
#import "NRTestConstants.h"
#import "NRAutoLogCollector.h"
#import <os/log.h>

@implementation NRLoggerTests
- (void) setUp
Expand Down Expand Up @@ -253,4 +255,89 @@ - (void) testRemoteLogLevels {
XCTAssertEqual(foundCount, 3, @"Three remote messages should be found.");
}

- (void) testAutoCollectedLogs {
[NRMAFlags enableFeatures: NRFeatureFlag_RedirectStdOutStdErr];
// Set the remote log level to Info.
[NRLogger setRemoteLogLevel:NRLogLevelDebug];
[NRAutoLogCollector redirectStandardOutputAndError];

XCTestExpectation *delayExpectation1 = [self expectationWithDescription:@"Waiting for Log Queue"];

dispatch_after(dispatch_time(DISPATCH_TIME_NOW, (int64_t)(5 * NSEC_PER_SEC)), dispatch_get_main_queue(), ^{
[delayExpectation1 fulfill];
});

[self waitForExpectationsWithTimeout:5 handler:^(NSError * _Nullable error) {
if (error) {
XCTFail(@"Timeout error");
}
}];

// Three messages should reach the remote log file for upload.
NSLog(@"NSLog Test");
os_log_t customLog = os_log_create("com.agent.tests", "logTest");
// Log messages at different levels
os_log(customLog, "This is a default os_log message.");
os_log_info(customLog, "This is an info os_log message.");
os_log_debug(customLog, "This is a debug os_log message.");
os_log_error(customLog, "This is an error os_log message.");
os_log_fault(customLog, "This is a fault os_log message.");

XCTestExpectation *delayExpectation2 = [self expectationWithDescription:@"Waiting for Log Queue"];

dispatch_after(dispatch_time(DISPATCH_TIME_NOW, (int64_t)(2 * NSEC_PER_SEC)), dispatch_get_main_queue(), ^{
[delayExpectation2 fulfill];
});

[self waitForExpectationsWithTimeout:5 handler:^(NSError * _Nullable error) {
if (error) {
XCTFail(@"Timeout error");
}
}];

NSError* error;
NSData* logData = [NRLogger logFileData:&error];
if(error){
NSLog(@"%@", error.localizedDescription);
}
NSString* logMessagesJson = [NSString stringWithFormat:@"[ %@ ]", [[NSString alloc] initWithData:logData encoding:NSUTF8StringEncoding]];
NSData* formattedData = [logMessagesJson dataUsingEncoding:NSUTF8StringEncoding];
NSArray* decode = [NSJSONSerialization JSONObjectWithData:formattedData
options:0
error:nil];
NSLog(@"decode=%@", decode);

NSArray * expectedValues = @[
@{@"message": @"NSLog Test"},
@{@"message": @"This is a default os_log message."},
@{@"message": @"This is an info os_log message."},
@{@"message": @"This is a debug os_log message."},
@{@"message": @"This is an error os_log message."},
@{@"message": @"This is a fault os_log message."},
];
// check for existence of 6 logs.
int foundCount = 0;
// For each expected message.
for (NSDictionary *dict in expectedValues) {
// Iterate through the collected message logs.
for (NSDictionary *dict2 in decode) {
//
NSString* currentMessage = [dict objectForKey:@"message"];
if ([[dict2 objectForKey:@"message"] containsString: currentMessage]) {
foundCount += 1;
XCTAssertTrue([[dict2 objectForKey:@"entity.guid"] isEqualToString:@"Entity-Guid-XXXX"],@"entity.guid set incorrectly");
}
// Verify added attributes with logAttributes.
if ([[dict2 objectForKey:@"message"] isEqualToString:@"This is a test message for the New Relic logging system."]) {
XCTAssertTrue([[dict2 objectForKey:@"additionalAttribute1"] isEqualToString:@"attribute1"],@"additionalAttribute1 set incorrectly");
XCTAssertTrue([[dict2 objectForKey:@"additionalAttribute2"] isEqualToString:@"attribute2"],@"additionalAttribute2 set incorrectly");
}
}
}

XCTAssertEqual(foundCount, 6, @"Three remote messages should be found.");

Check failure on line 338 in Tests/Unit-Tests/NewRelicAgentTests/Uncategorized/NRLoggerTests.m

View workflow job for this annotation

GitHub Actions / TestWatchOS

testAutoCollectedLogs, ((foundCount) equal to (6)) failed: ("0") is not equal to ("6") - Three remote messages should be found.
[NRAutoLogCollector restoreStandardOutputAndError];
[NRMAFlags disableFeatures: NRFeatureFlag_RedirectStdOutStdErr];
}

@end

0 comments on commit 3d1ca9c

Please sign in to comment.