Missing Logoff event(538) when Fspy is loaded.

NTFSD
1

Hi

Detail description:

I am maintaining one huge legacy FS filter driver. There is a issue reported from customer that when driver is loaded, system delays the logoff event(538).
Means:

  1. telnet localhost generates session id A

  2. exit from this session doesn’t generate any logoff event.

  3. One more telnet localhost generates session id B

  4. Again on exit of this session, no logoff event is registered.

  5. Now new telnet localhost session generates session id C and also generates the logoff event for A.

  6. On exiting of the session C, doesn’t generate any logoff event.

  7. Now any new session (telnet or anything) will generate logoff event for previous to previous session.

I verified that my driver is not getting any IRP_MJ_WRITE(For any fastio, my driver returns false)when I exit any session, for the file SecEvent.evt.
During the investigation, I found tool filespy from OSR’s download section and to my great surprise, it also has the similar problem. When Fspy is loaded , I don’t get any logoff event.
I tried both the version of filespy, one from osr’s website and other from Ladislav’s website.

I verified Microsoft filespy driver behavior also. It works fine (I compiled for win2k3 server and win2k server, both works fine on win2k3 server).

I am writing you this mail, to get help in understanding the problem. Please let me know if you need any more detail.
I will really appreciate any help.

Some of my finding:
SecEvent.evt is used by services.exe as memory mapped file and it is loaded at boot time.
My driver doesn’t handle any of the ForCcFlush, ForCcModWrite, ForNtCreateSection. But filespy from Microsoft handles it.
I disable the code in the Microsoft’s filespy which registered handlers for these operation, but still it didn’t give any issue.

Thanks
Manish

________________________________

http://www.mindtree.com/email/disclaimer.html

2

Doesn’t your filter capture security context (SeCaptureSubjectContext() API) or reference primary or impersonation token? It might hold logon session running.

Bronislav Gabrhelik

3

Thanks for your reply.

My problem is when my filter driver is running, Security Event log(EventViewer->Security) register the logoff event for previous to previous logon session. i.e. We can see logoff event in Eventviewer as delayed.

Also, the filespy from OSR has a problem of not getting logoff event available in same security event log.
i.e. we cannot see any logoff event(event id 538) in Event viewer

Thanks
Manish

4

Hi,

One correction in the details description of problem

  1. Now new telnet localhost session generates session id C and also generates the logoff event for A.

corrected as

  1. Now new telnet localhost session generates session id C and also generates the logoff event for B.

Sorry, for mistake.

Thanks
Manish

5

No results yet, just for the sake of letting you know that I work on it:

So far, I found out that the logoff event is initiated directly by Windows kernel when a reference count for the active session drops to zero. I can confirm that the issue exists, and apparently is not related to FSpy.sys only, but also occurs with MSpy.sys (minifilter driver, based on WDK’s Minispy). So far, I haven’t found the reason.

6

http://www.monitorware.com/common/en/securityreference/event-id-538-expl
ained.php

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@volny.cz
Sent: Tuesday, December 07, 2010 1:36 PM
To: Windows File Systems Devs Interest List
Subject: RE:[ntfsd] Missing Logoff event(538) when Fspy is loaded.

No results yet, just for the sake of letting you know that I work on it:

So far, I found out that the logoff event is initiated directly by
Windows kernel when a reference count for the active session drops to
zero. I can confirm that the issue exists, and apparently is not related
to FSpy.sys only, but also occurs with MSpy.sys (minifilter driver,
based on WDK’s Minispy). So far, I haven’t found the reason.

NTFSD is sponsored by OSR

For our schedule of debugging and file system seminars
(including our new fs mini-filter seminar) visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at
http://www.osronline.com/page.cfm?name=ListServer

7

FileSpy.exe installs the driver using:

OpenSCManager
OpenService (to check if it exists)
CreateService (if it doesn’t)
StartService
CloseServiceHandle(hSCManager)
CloseServiceHandle(hService)

After this, there is an extra reference to the process token, caused by CreateService. This reference prevents the system from deleting the token, and from deletting the session as consequence.

FileSpy.exe doesn’t delete the service, because I want users to be able to start it under limited account (RunFileSpy undes admin - relog - run FileSpy as normal user). It would probably be possible to use NtLoadDriver instead of service manager, In that case, Service Control Manager would not get involved at all, so it might solve the token leak. But I am not really sure if I want that.

8

Thanks Ladislav for your response.

But for my driver it looks like as Bronislav mentioned earlier, there is probably missing SeReleaseSubjectContext for SeCaptureSubjectContext.

I am right now looking into it. I will update this post on any progress.

Thanks Bronislav, your suggestion.
My driver calls SeCaptureSubjectContext for each new FCB in IRP_MJ_CREATE and calls corresponding SeReleaseSubjectContect in IRP_MJ_CLOSE. Now i am going in that direction to see what is wrong.

Thanks
Manish

9

Are you working with security contexts in your FSF?

–
Maxim S. Shatskih
Windows DDK MVP
xxxxx@storagecraft.com
http://www.storagecraft.com

10

Yes Maxim, I am working with security context.

I capture security context in the IRP_MJ_CREATE and release it in the IRP_MJ_CLOSE.

After my last update, I did some experiment.

to confirm the problem, i commented out the code to capture and release the security context. After that telnet session exit properly showed the logoff event.

Once I confirmed the problem, I logged all the files opened and close during telnet sessions. Then tried eliminate all the files which has create and close pair.

I found only one file \windows\system32\termcap doesn’t have matching close. After detailed investigation, I found

  1. On first telnet connection IRP_MJ_CREATE and IRP_MJ_CLEANUP is issued for the termcap but no IRP_MJ_CLOSE. On exit of telnet session no operation on the file.

  2. On second telnet connection IRP_MJ_CREATE is issued for new fileobject for termcap , IRP_MJ_CLOSE for the fileobject opened during first session, and IRP_MJ_CLEANUP for fileobject of current session.

  3. This goes on.

Above sequence happens with or without any filter driver (except Filter manager)

Then I changed the code to not to capture/release security context when the file is termcap. But I am still getting the same issue for the loggoff event.

Please let me know, where to look further.

All the previous post really helped me to track problem down to security context.

Thanks
Manish

11

Can you describe some details? What API do you use. What do you do with security context between Create & Close? If you impersonate how do you revert back impersonation? etc…

Bronislav Gabrhelik

12

I use SeCaptureSubjectContext in the IRP_MJ_CREATE before passing down the request. In use SeReleaseSubjectContext in the completion of IRP_MJ_CLOSE.

Basically My filter monitors I/O s on the file. The files needs to be monitor will be decided by user and will be give to filter as IOCTL . When my filter is monitoring any file, It will log all the I/O operation on the file, such that it can replay it. Now, to log the IRP_MJ_SET_INFORMATION, properly I need context of the thread which has opened the file. So, I use captured context to record IRP_MJ_SET_INFORMATION, by impersonating the captured context.

But in this scenario, I am not monitoring any file. So, I am not using the captured context anywhere.

Please let me know, if any more information is required.

Thanks
Manish