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.

Sign up for GitHub

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

Jump to bottom

Mac: prjfs-log improvements #158

Merged
merged 2 commits into from
Aug 14, 2018
Merged

Mac: prjfs-log improvements #158

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
9807d51
Log improvements: build everything under one target, added utility fo…
sanoursa Aug 13, 2018
34fc540
Print the timestamp in the message rather than the current time
sanoursa Aug 14, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions ProjFS.Mac/PrjFS.xcworkspace/xcshareddata/WorkspaceSettings.xcsettings
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,8 @@
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
<key>IDEWorkspaceSharedSettings_AutocreateContextsIfNeeded</key>
<false/>
</dict>
</plist>
14 changes: 14 additions & 0 deletions ProjFS.Mac/PrjFS.xcworkspace/xcshareddata/xcschemes/PrjFS.xcscheme
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,20 @@
ReferencedContainer = "container:PrjFSLib/PrjFSLib.xcodeproj">
</BuildableReference>
</BuildActionEntry>
<BuildActionEntry
buildForTesting = "YES"
buildForRunning = "YES"
buildForProfiling = "YES"
buildForArchiving = "YES"
buildForAnalyzing = "YES">
<BuildableReference
BuildableIdentifier = "primary"
BlueprintIdentifier = "D308477D20B4431200F69E92"
BuildableName = "prjfs-log"
BlueprintName = "prjfs-log"
ReferencedContainer = "container:PrjFSLib/PrjFSLib.xcodeproj">
</BuildableReference>
</BuildActionEntry>
</BuildActionEntries>
</BuildAction>
<TestAction
Expand Down
9 changes: 5 additions & 4 deletions ProjFS.Mac/PrjFSKext/PrjFSKext/KextLog.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -81,6 +81,11 @@ void KextLog_DeregisterUserClient(PrjFSLogUserClient* userClient)

void KextLog_Printf(KextLog_Level loglevel, const char* fmt, ...)
{
if (nullptr == s_currentUserClient)
{
return;
}

// Stack-allocated message with 128-character string buffer for fast path
struct KextLog_StackMessageBuffer message = {};
KextLog_MessageHeader* messagePtr = &message.header;
Expand Down Expand Up @@ -122,10 +127,6 @@ void KextLog_Printf(KextLog_Level loglevel, const char* fmt, ...)
messagePtr->machAbsoluteTimestamp = time;
s_currentUserClient->sendLogMessage(messagePtr, messageSize);
}
else
{
kprintf("%s\n", messagePtr->logString);
}
}
RWLock_ReleaseShared(s_kextLogRWLock);

Expand Down
42 changes: 42 additions & 0 deletions ProjFS.Mac/PrjFSKext/PrjFSKext/KextLog.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,5 +42,47 @@ template <typename... args>
#define KextLog_FileInfo(vnode, format, ...) ({ _os_log_verify_format_str(format, ##__VA_ARGS__); KextLogFile_Printf(KEXTLOG_INFO, vnode, format " (vnode path: '%s')", ##__VA_ARGS__); })
#define KextLog_FileNote(vnode, format, ...) ({ _os_log_verify_format_str(format, ##__VA_ARGS__); KextLogFile_Printf(KEXTLOG_NOTE, vnode, format " (vnode path: '%s')", ##__VA_ARGS__); })

#define KextLog_VnodeOp(vnode, vnodeType, procname, action, message) \
do { \
if (VDIR == vnodeType) \
{ \
KextLog_FileNote( \
vnode, \
message ". Proc name: %s. Directory vnode action: %s%s%s%s%s%s%s%s%s%s%s%s%s \n ", \
procname, \
(action & KAUTH_VNODE_LIST_DIRECTORY) ? " \n KAUTH_VNODE_LIST_DIRECTORY" : "", \
(action & KAUTH_VNODE_ADD_FILE) ? " \n KAUTH_VNODE_ADD_FILE" : "", \
(action & KAUTH_VNODE_SEARCH) ? " \n KAUTH_VNODE_SEARCH" : "", \
(action & KAUTH_VNODE_DELETE) ? " \n KAUTH_VNODE_DELETE" : "", \
(action & KAUTH_VNODE_ADD_SUBDIRECTORY) ? " \n KAUTH_VNODE_ADD_SUBDIRECTORY" : "", \
(action & KAUTH_VNODE_DELETE_CHILD) ? " \n KAUTH_VNODE_DELETE_CHILD" : "", \
(action & KAUTH_VNODE_READ_ATTRIBUTES) ? " \n KAUTH_VNODE_READ_ATTRIBUTES" : "", \
(action & KAUTH_VNODE_WRITE_ATTRIBUTES) ? " \n KAUTH_VNODE_WRITE_ATTRIBUTES" : "", \
(action & KAUTH_VNODE_READ_EXTATTRIBUTES) ? " \n KAUTH_VNODE_READ_EXTATTRIBUTES" : "", \
(action & KAUTH_VNODE_WRITE_EXTATTRIBUTES) ? " \n KAUTH_VNODE_WRITE_EXTATTRIBUTES" : "", \
(action & KAUTH_VNODE_READ_SECURITY) ? " \n KAUTH_VNODE_READ_SECURITY" : "", \
(action & KAUTH_VNODE_WRITE_SECURITY) ? " \n KAUTH_VNODE_WRITE_SECURITY" : "", \
(action & KAUTH_VNODE_TAKE_OWNERSHIP) ? " \n KAUTH_VNODE_TAKE_OWNERSHIP" : ""); \
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How messy would the output be to separate these with | rather than newlines?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Depends on the event. Sometimes we'll see 3-4 actions in a single kauth event. I'm not opposed to reformatting this though.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm good with going what you have now and we can see how it feels in practice

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yep feel free to clean it up if the multiple lines gets to be too much

} \
else \
{ \
KextLog_FileNote( \
vnode, \
message ". Proc name: %s. File vnode action: %s%s%s%s%s%s%s%s%s%s%s%s \n ", \
procname, \
(action & KAUTH_VNODE_READ_DATA) ? " \n KAUTH_VNODE_READ_DATA" : "", \
(action & KAUTH_VNODE_WRITE_DATA) ? " \n KAUTH_VNODE_WRITE_DATA" : "", \
(action & KAUTH_VNODE_EXECUTE) ? " \n KAUTH_VNODE_EXECUTE" : "", \
(action & KAUTH_VNODE_DELETE) ? " \n KAUTH_VNODE_DELETE" : "", \
(action & KAUTH_VNODE_APPEND_DATA) ? " \n KAUTH_VNODE_APPEND_DATA" : "", \
(action & KAUTH_VNODE_READ_ATTRIBUTES) ? " \n KAUTH_VNODE_READ_ATTRIBUTES" : "", \
(action & KAUTH_VNODE_WRITE_ATTRIBUTES) ? " \n KAUTH_VNODE_WRITE_ATTRIBUTES" : "", \
(action & KAUTH_VNODE_READ_EXTATTRIBUTES) ? " \n KAUTH_VNODE_READ_EXTATTRIBUTES" : "", \
(action & KAUTH_VNODE_WRITE_EXTATTRIBUTES) ? " \n KAUTH_VNODE_WRITE_EXTATTRIBUTES" : "", \
(action & KAUTH_VNODE_READ_SECURITY) ? " \n KAUTH_VNODE_READ_SECURITY" : "", \
(action & KAUTH_VNODE_WRITE_SECURITY) ? " \n KAUTH_VNODE_WRITE_SECURITY" : "", \
(action & KAUTH_VNODE_TAKE_OWNERSHIP) ? " \n KAUTH_VNODE_TAKE_OWNERSHIP" : ""); \
} \
} while (0)

#endif /* KextLog_h */
11 changes: 8 additions & 3 deletions ProjFS.Mac/PrjFSLib/prjfs-log/prjfs-log.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,6 @@
#include <IOKit/IOKitLib.h>
#include <mach/mach_time.h>


static const char* KextLogLevelAsString(KextLog_Level level);

int main(int argc, const char * argv[])
Expand All @@ -24,7 +23,9 @@ int main(int argc, const char * argv[])
std::cerr << "Failed to set up shared data queue.\n";
return 1;
}


__block int lineCount = 0;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is the __block required here because of something with Objective-C?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not Objective-C per se. Apple's C++ compiler has an extension to support blocks, which is how we can call the dispatch_source_set_event_handler function down below. This __block flag is required to indicate that you want to be able to modify a variable inside a block.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ahh okay thanks! I missed that dispatch_source_set_event_handler was in a block.


dispatch_source_set_event_handler(dataQueue.dispatchSource, ^{
struct {
mach_msg_header_t msgHdr;
Expand All @@ -39,15 +40,19 @@ int main(int argc, const char * argv[])
{
break;
}

int messageSize = entry->size;
if (messageSize >= sizeof(KextLog_MessageHeader) + 2)
{
struct KextLog_MessageHeader message = {};
memcpy(&message, entry->data, sizeof(KextLog_MessageHeader));
const char* messageType = KextLogLevelAsString(message.level);
int logStringLength = messageSize - sizeof(KextLog_MessageHeader) - 1;
printf("%s: %.*s\n", messageType, logStringLength, entry->data + sizeof(KextLog_MessageHeader));

printf("(%d: %llu) %s: %.*s\n", lineCount, message.machAbsoluteTimestamp, messageType, logStringLength, entry->data + sizeof(KextLog_MessageHeader));
lineCount++;
}

IODataQueueDequeue(dataQueue.queueMemory, nullptr, nullptr);
}
});
Expand Down