Analysis of Apple Unified Logs: Quarantine Edition [Entry 8] – Man! What a process!?

May 19, 2020 in logs, macos

A quick trick to get more info when you are testing different Unified log examples is to use Terminal’s man page lookup feature. This is useful to provide more context to processes that you may not be familiar with. Perhaps you have something interesting in the eventMessage field and want to know more about what processes use that information.

In this example, I “right-clicked” some of the process names to get more information about them; sharingd, bluetoothd, and powerd. However, identifityservicesd does not have a man page so I’ll have to research that one another way!

Analysis of Apple Unified Logs: Quarantine Edition [Entry 7] – Exploring USBMSC devices with --style

May 04, 2020 in logs, macos, analysis

There are many output styles options for the ‘log’ command. Sometimes the default output may not get you what you want. This article will walk through the various log output styles looking for USB Mass Storage Class devices using the keyword ‘USBMSC ‘. These devices may include thumb drives and external hard drives as long as they are considered Mass Storage Class devices.

These entries get created when they are inserted into macOS systems. The output of these entries includes:

The “non-unique” identifiers – usually the serial number of the device, but as it suggests it may not necessarily be unique.
Vendor ID
Product ID
Version

Using --style we can change the output to something that is perhaps more appropriate. This can also be a personal preference. The output styles are listed in the ‘man’ page.

In the query below, I am searching my logs for these types of devices with the ‘default’ output option. I’m looking for the string ‘USBMSC’ in the event messages.

log show --predicate "eventMessage contains 'USBMSC'"

The default output contains quite a few columns:

Timestamp (with microseconds and time zone)
Thread ID
Log Type
Activity ID
Process ID
TTL
Process
Subsystem
Category
Message

Other than the ‘default’ style, we will need to specific the style we want with --style. First up in ‘compact’.

log show --predicate "eventMessage contains 'USBMSC'" --style compact

The compact option removes the Activity ID and TTL from the ‘default’ output while compressing other fields.

Timestamp (with milliseconds and no time zone)
Log Type (abbreviated)
Process
Process ID
Thread ID
Subsystem
Category
Message

The next couple of log output styles is ‘json’ and ‘ndjson’. The first being json with whitespace, while the second is a single line for each entry. I’ve highlighted each entry to better show the structure in these two examples. I like how the json output shows the full paths for senderImagePath and processImagePath. It also shows a quite a few additional fields. Not exactly human-readable for more than a few entries, but this could be imported into another viewer or pumped through scripting utilities.

log show --predicate "eventMessage contains 'USBMSC'" --style json

log show --predicate "eventMessage contains 'USBMSC'" --style ndjson

One thing I miss with this JSON output is the colorization. While there is a --color argument in ‘log’, it doesn’t seem to apply to JSON style output. However, I can use the tried and trusted ‘jq’ command line JSON parser here.

The last output example is ‘syslog’. If you’ve been looking at Apple System Logs (ASL) or other syslog style logs, you might prefer this output format.

log show --predicate "eventMessage contains 'USBMSC'" --style syslog

This style is useful if you need an even more compact view than using the ‘compact’ style. Again, the colorization is removed from these entries (--color doesn’t appear to work here either).

Analysis of Apple Unified Logs: Quarantine Edition [Entry 6] – Working From Home? Remote Logins

April 30, 2020 in logs, macos, analysis

I’m sure many of us are working remote right now possibly using some of these remote capabilities. Remote Logins can include a few different services; SSH and Screen Sharing are two that I’ll show here. These services are disabled by default and would need to be turned on in the user’s Sharing preferences.

When Remote Login is turned on in the Sharing preferences, the system will have an SSH server enabled. Let’s take a look at what an incoming SSH connection might look like first for a user account on the system that does not have this option turned on (janedoe). We are looking for the entries for the process ‘sshd’.

log show --predicate 'process = "sshd"'

One entry to key in on is the “user account has expired”. A user attempted to use SSH to login to this system using the ‘janedoe’ account coming from IP 192.168.1.170, however the connection failed.

Now on a system that does have remote login turned on. This first example shows an incorrect password attempt.

And a correct password attempt and login.

Connections can of course be incoming or outgoing. If the user were trying to access another system it might look like this. Not a whole lot unfortunately.

log show --info --predicate 'process = "ssh" or eventMessage contains "ssh"'

…and when the connection closes.

Screen Sharing is another service that needs to be explicitly enabled in the Sharing preferences. Incoming connections will show the user who logged in and where they came from. The example below shows an incorrect password that failed, and another that was correct. I’ve only queried for messages that contain the text ‘Authentication:’. Looking for all messages associated with the ‘screensharingd’ process will be quite verbose with some metadata about the session.

log show --predicate 'process = "screensharingd" and eventMessage contains "Authentication:"'

Outgoing connections, like incoming connections, can be verbose. The process is ‘Screen Sharing’ like the application name.

log show --info --predicate 'process = "Screen Sharing"'

I might do a specific filter for ‘connect’ and ‘disconnect’ in the messages to see multiple sessions over time.

Analysis of Apple Unified Logs: Quarantine Edition [Entry 5] – Login Inception!? Yes! – Local Logins!

April 28, 2020 in logs, macos, analysis

Local logins are created when an already logged in user opens a Terminal window. Each terminal window is a separate ‘login’ process. If you have six Terminal windows (or tabs) open, you have six ‘login’ processes.

In the last article, I showed how you can find these processes using other log types. Let’s see what local logins look like in unified logs. Trying to create a query from these, I ran into an issue trying to filter for the ‘login’ process which makes a great learning example.

If I try to use ‘processImagePath’ I get lots of unnecessary entries from ‘loginwindow’ or any other process that might have ‘login’ in the name. This is because the process that we see in the default ‘log’ output is actually part of a path as the field ‘processImagePath’ suggests.

log show --predicate 'processImagePath contains "login"'

We can use a different output style to see these paths. I used JSON for the output in the screenshot below.

log show --predicate 'process contains "login"' --style json

To filter specifically for the ‘login’ process, I will use ‘process’ instead of ‘processImagePath’ which will just filter on the process name. As an example, I changed ‘contains’ to ‘=’ in the first command line to show it is looking for just the term ‘login’. This shows no results due to using ‘processImagePath’ instead of ‘process’.

log show --predicate 'process = "login"'

Getting back to those ‘login’ processes, I created the query below. While not perfect it does show some interesting items.

log show --info --predicate '(processImagePath contains "opendirectory" and eventMessage contains "Client:") or process = "login"'

In this test, I just opened a new tab in Terminal and performed a few commands.

The query output shows the ‘login’ process as well as a few ‘open directory’ entries. Not all of these are related to this Terminal action, but these can be visually filtered out by using process IDs (40881, 40882). While this does show a new Terminal window opening via the ‘login’ process we also see the exiting action for ‘zsh’ and ‘login’.

Unfortunately, I have found that these particular ‘opendirectoryd’ processes will expire in a very short time period (~90 minutes) therefore I might revert back to other logs to extract this information as show in this syslog output.

Can you really have ‘login’ inception? Yes! (I’m using the ‘login’ command here to login to various user accounts in the same shell. 🤪)

Analysis of Apple Unified Logs: Quarantine Edition [Entry 4] – It’s Login Week!

April 26, 2020 in logs, macos, analysis

No one can find flour or yeast anyway! 😆

This week is all about system logins! On the system (via password, TouchID, or Apple Watch), local logins using Terminal, and remote logins over SSH and Screen Sharing. There are many ways of accessing a macOS system, certainly this is not all inclusive but should cover many investigative scenarios.

Let’s start with Login Window logins. These are the types of user logins that I like to call “hands-on-keyboard” at a GUI login screen. You are looking at a Mac system and log in.

The complexity of these logins has changed quite a bit over the last few years with the introduction of TouchID and Auto Login with the Apple Watch.

First, let’s review what these log entries used to look like. In reality, many of these entries still exist in these logs. Just a reminder here that there are other logs on the system that you may still need to review! These particular logs can be found in /private/var/log/system.log (and archived versions) as well as the Apple System Logs (ASL) in the /private/var/log/asl directory.

Starting with system.log and its archived versions, I’m looking for entries that contain the string “_PROCESS”. I used ‘gzcat’ to extract the messages from the gzip archives and ‘cat’ for the current system.log file.

gzcat system.log.{1..0}.gz | grep _PROCESS && cat system.log | grep _PROCESS

A USER_PROCESS is a logon while DEAD_PROCESS is a logoff. These are tied together with a process ID that follows it. The facilities that record the message tell what type of login it is.

loginwindow – These are the “hands-on-keyboard” logins that I’ll be talking about in this particular post.
login – These logins are local logins, you’ll see these with each Terminal window you have open.
sessionlogoutd – Pair these with the loginwindow login entries. This is the logout.
Not shown in the screenshot is remote logins via SSH. These have the ‘sshd’ facility.

These entries don’t provide a whole lot of context. They don’t tell me which user is logging in or how (Password, TouchID, or Apple Watch)

Another log that contains similar information are the Apple System Logs (ASL). In the example, I’ve parsed these out using ‘syslog’ with a raw output format and UTC timestamps. Note I’m only showing the first three entries as these are fairly verbose. The only additional context these provide is the user logging on and where they are coming from if it is a remote login. (The raw output format is needed to see this, otherwise the output looks similar to system.log entries.)

syslog -F raw -T UTC | grep "_PROCESS"

The third place to look for these entries is the Basic Security Module (BSM) Audit trail logs. These can be parsed with ‘praudit’. A single login entry is show below, no one likes looking at these logs due to their multi-token format.

One good thing about these is that they seemed to be retained longer than system.log and ASL which has been seemingly cut down in Catalina (10.15) to about 3 days from ~7 days in system.log and ~365 days in ASL for login entries. (Oddly, the ASL Expire times are a year out as they were in previous macOS versions. 🤷🏻‍♀️)

These are all great places to look but we need more context. To the Unified Logs! The problem with unified logs is that they can be very verbose, just looking at my ‘loginwindow’ process entries for a day, I have about 20k! There is no way I’m going to scroll through and attempt to interpret each entry. I need to filter for specific entries. I’ve come up with a few useful queries to find specific pieces of information.

The first is looking for messages that contain ‘com.apple.sessionagent.screenIs’ string. This is going to show if the system is locked or unlocked, and which user is currently logged in with their user ID (UID). These are not technically logins since the user is already logged in but are useful for telling if the screen is locked or not

com.apple.sessionagent.screenIsLocked = Screen is Locked
com.apple.sessionagent.screenIsUnlocked = Screen is Unlocked

log show --predicate 'eventMessage contains "com.apple.sessionagent.screenIs"'

To determine when the user did a true login (versus just a screen unlock) we can look for com.apple.sessionDidLogin in the message while specifically looking at the ‘loginwindow’ process.

log show --predicate 'processImagePath contains "loginwindow" and eventMessage contains "com.apple.sessionDidLogin"'

I really like the messages associated with ‘SessionAgentNotificationCenter’. They are easy to interpret which is why I chose them for these examples. I created a broader query to get more details about these login sessions to include the following entries:

com.apple.system.loginwindow.shutdownInitiated – User chose to shutdown system
com.apple.system.loginwindow.logoutcancelled – User canceled the shutdown (or restart or logoff)
com.apple.system.loginwindow.restartinitiated – User chose to restart system

log show --predicate 'eventMessage contains "com.apple.system.loginwindow" and eventMessage contains "SessionAgentNotificationCenter"'

You might notice a couple UID’s in these examples (501 and 502). This is me going back and forth between accounts using Fast User Switching which can be filtered for by using ‘com.apple.fastUserSwitchBegin’.

Keeping track of what we have so far using ‘SessionAgentNotificationCenter’

Screen Lock/Unlock Status
User Logons
User Logoff
Restarts (w/UID)
Shutdown (w/UID)
Fast User Switching
Canceled Restart/Shutdown/Logoff

To get all these ‘SessionAgentNotificationCenter’ messages try using this query:

log show --predicate 'eventMessage contains "SessionAgentNotificationCenter"'

Password, TouchID, or Apple Watch?

So many loginwindow logins but which type! Is it a normal password login, using TouchID, or Auto Unlock using their Apple Watch? I find the messages that contain ‘LWScreenLockAuthentication’ are good for this. I’ve also added the strings ‘| Verifying’ and ‘| Using’ to filter it further.

log show --predicate 'eventMessage contains "LWScreenLockAuthentication" and (eventMessage contains "| Verifying" or eventMessage contains "| Using")'

The screenshot above contains the three different types of logins.

Regular Password:

“Verifying using PAM configuration screensaver”

TouchID:

“Using localAuthentication hints”
“Using hint-provided username oompa”
“Verifying using PAM configuration screensaver_la”

Auto Unlock with Apple Watch:

“Using continuity hints”
“Using hint-provided username oompa”
“Verifying using PAM configuration screensaver_aks”

To get more detail I want to look at messages for ‘LWDefaultScreenLockUI’. I’ve combined these entries together in a long query looking for specific keywords.

log show --predicate 'eventMessage contains "LWDefaultScreenLockUI" and (eventMessage contains "authSuccess" or eventMessage contains "authFailWithMessage" or eventMessage contains "loginPressed" or eventMessage contains "authBegan" or eventMessage contains "preLoad")'

The keyword ‘preload’ provides us some metadata about the system.

fmmEnabled – Find my Mac is Enabled
fusEnabled – Fast User Switching is Enabled
The number of user accounts are on the system

The next set shows if the login was successful or not.

loginPressed – Password Attempt Number (Attempt #: ?)
- If someone is attempting to brute force via typing in passwords you’ll see the number of attempts tick up.
authBegan – Begin Authentication
authFailWithMessage – Authentication Failed
authSuccess – Authentication Successful