Troubleshooting RunOnce entries: Part One

I’ve been investigating the root cause for a critical issue
affecting my CacheMyWork app (for those of you paying attention, it has come up in the past in this column). Ever since I received my (heavily-managed) corporate laptop at work, I’ve been unable to get Windows XP to launch any of the entries that CacheMyWork populates in RunOnce.

Here’s what I knew up front

  • On other Windows XP and Windows Vista systems, the same version of CacheMyWork will result in RunOnce entries that all launch at next logon
  • On the failing system, the entries are still being properly populated into the Registry – after running the app, I’ve checked and the entries under RunOnce are there as expected and appear to be well-formatted
  • The Event Log (System and Application) doesn’t log any records that refer even peripherally to RunOnce, let alone that there are any problems or what might be causing them
  • The entries haven’t disappeared as late as just before I perform a logoff (i.e. they’re not being deleted during my pre-reboot session).

Here’s what I tried

UserEnv logging
  • I added HKLM\Software\Microsoft\Windows NT\CurrentVersion\Winlogon\UserEnvDebugLevel = 30002 (hex).
  • This is able to show that the processes I’m observing are firing up correctly, but there is nothing in the log that contains “runonce” or the names of the missing processes, and I haven’t spotted any entries in the log that point me to any problems with the RunOnce processing.
ProcMon boot-time logging
  • I’ve got over 3.3 million records to scan through, so while I haven’t found anything really damning, I may never be 100% sure there wasn’t something useful.
  • After a lot of analysis, I found a few interesting entries in the ProcMon logs:
Process Request Path Data
mcshield.exe RegQueryValue HKLM\SOFTWARE\Network Associates\TVD\Shared Components\On Access Scanner\BehaviourBlocking\FileBlockRuleName_2 Prevent Outlook from launching anything from the Temp folder
mcshield.exe RegQueryValue HKLM\SOFTWARE\Network Associates\TVD\Shared Components\On Access Scanner\BehaviourBlocking\FileBlockRuleName_10 Prevent access to suspicious startup items (.exe)
mcshield.exe RegQueryValue HKLM\SOFTWARE\Network Associates\TVD\Shared Components\On Access Scanner\BehaviourBlocking\FileBlockWildcard_10 **\startup\**\*.exe
BESClient.exe RegOpenKey HKLM\Software\Microsoft\Windows\CurrentVersion\RunOnce Query Value
Explorer.exe RegEnumValue HKLM\Software\Microsoft\Windows\CurrentVersion\RunOnce Index: 0, Length: 220
waatservice.exe RegOpenKey HKLM\Software\Microsoft\Windows\CurrentVersion\RunOnce Desired Access: Maximum Allowed
Windows Auditing

I finally got the bright idea to put a SACL (audit entry) on the HKCU\…\RunOnce registry key (auditing any of the Successful “Full Control” access attempts for the Everyone special ID). After rebooting, I finally got a hit on the HKCU\…\RunOnce key:

Event Log data

First log entry

Second log entry

Third log entry

Category Object Access Object Access Object Access
Event ID 560 567 567
User (my logon ID) (my logon ID) (my logon ID)

And here are the interesting bits of Description data for each:

Description field

First log entry

Second log entry

Third log entry

Title Object Open: Object Access Attempt: Object Access Attempt:
Object Type Key Key Key
Object Name \REGISTRY\USER\S-1-5-21-725345543-602162358-527237240-793951\Software\Microsoft\ Windows\CurrentVersion\RunOnce [n/a] [n/a]
Image File Name C:\WINDOWS\explorer.exe C:\WINDOWS\explorer.exe C:\WINDOWS\explorer.exe
Accesses

DELETE
READ_CONTROL
WRITE_DAC
WRITE_OWNER
Query key value
Set key value
Create sub-key
Enumerate sub-keys
Notify about changes to keys
Create Link

[n/a] [n/a]
Access Mask [n/a] Query key value Set key value

Not that I’ve ever looked this deep into RunOnce behaviour (nor can I find any documentation to confirm), but this seems like the expected behaviour for Windows. Except for the fact that something is preventing the RunOnce commands from executing, of course.

Blocking the Mystery App?

Then I thought of something bizarre: maybe Explorer is checking for RunOnce entries to run during logon, and it isn’t finding any. Is it possible some process has deleted them during boot-up or logon, but before Explorer gets to them?

This flies in the face of my previous theory, that the entries were still there when Windows attempted to execute them, but something was blocking their execution. Now I wondered if the entries are even there to find – whether some earlier component hasn’t already deleted them (to “secure” the system).

If so, the only way to confirm my theory (and catch this component “in the act”) is if the component performs its actions on the Registry AFTER the LSA has initialized and is protecting the contents of the Registry. [It’s been too long since I read Inside Windows NT, so I don’t recall whether access to securable objects is by definition blocked until the LSA is up and ready.]

Hoping this would work, I enabled “Deny” permission for Everyone on the HKCU\…\RunOnce key for both “Set Value” and “Delete” (not knowing which one controls the deletion of Registry values in the key). This also meant that I had to enable Failure “Full Control” auditing for the Everyone group on this key as well.

However, while I’ve firmly confirmed that the Deletion takes place when I remove this Deny ACE, I can’t get Windows to log any information to indicate what process or driver is deleting the registry entries (and thus preventing Windows from executing them). It looks like – beyond what I’ve already found – there’s nothing else for which the LSA is asked to make any access control decisions for the HKCU\…\RunOnce key.

“Run Away!”

That’s all for now – I’m beat and need to regroup. If anyone has any bright ideas on ways to try to dig deeper into this system and figure out what’s missing, I’d love to hear it.

To be continued…

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s