Chapters

  1. Introduction
  2. Structure
  3. Packaging
  4. Logging
  5. Configuration
  6. Debugging EXEs
  7. Handling errors
  8. Testing
  9. Documentation
  10. Make
  11. Providing help
  12. Scheduled Tasks
  13. Windows Services
  14. Windows Event Log
  15. Windows Registry
  16. Creating SetUp.exe
  17. Regular Expressions
  18. Acre
  19. GUI
  20. Git

Appendices

  1. Windows environment vars
  2. User commands
  3. aplcores & WS integrity
  4. Development environment
  5. Special characters

Misc

Now that we have managed to establish MyApp as a Windows Service we need to ensure it behaves. We shall make it report to the Windows Event Log.

The Windows Event Log is by no means an alternative to application-specific log files. Most ordinary applications do not write to the Windows Event Log at all, some do only when things go wrong, and a very few, always.

In other words, for ordinary applications you may or may not find useful information in the Windows Event Log.

In contrast, an application that runs as a Windows Service is expected to write to the Windows Event Log when it starts, when it quits and when it encounters problems, and it might add even more information. There are few exceptions.

Similarly, Scheduled Tasks are expected to do the same, although some don't, or report only errors.

On a server, all applications run either as Windows Services (most likely all of them) or as Windows Scheduled Tasks. Since no human is sitting in front of a server we need a way to detect problems on servers automatically.

That can be achieved by using software that constantly scans the Windows Event Log. It can email or text admins when an application that's supposed to run doesn't, or when an application goes astray, drawing attention to that server.

In large companies, which usually manage many servers, it is common to use software that checks the Windows Event Logs of all those servers.

So yes, the Windows Event Log is indeed important. Really important.

In modern versions of Windows you just press the Win key and type Event. That brings up a list which contains at least Event Viewer.

By default, the Event Viewer displays all Event Logs on the current (local) machine. However, you can connect to another computer and investigate its Event Log, if you have the right permissions. Here we keep it simple, and focus just on the local Windows Event Log.

From the Microsoft documentation:

Each log in the Eventlog key contains subkeys called event sources. The event source is the name of the software that logs the event. It is often the name of the application or the name of a subcomponent of the application if the application is large.

You can add a maximum of 16,384 event sources to the registry. The Security log is for system use only. Device drivers should add their names to the System log. Applications and services should add their names to the Application log or create a custom log.[1]

The great majority of applications that write to the Windows Event Log write into Windows Logs\Application, but if you wish you can create your own log under Applications and services logs.

For creating a custom log you need admin rights. So creating a custom log is something usually done by the installer for your software, since it needs admin rights by definition anyway.

We keep it simple here, and write to the Application log.

Copy Z:\code\v13 to Z:\code\v14.

Note that any attempt to write to the Windows Event Log with the WindowsEventLog class requires the Dyalog .NET bridge to be a sibling of the EXE, be it the Dyalog EXE or a custom stand-alone EXE.

We are going to make MyApp write to the Windows Event Log only when it runs as a Service. Therefore we need to load the class WindowsEventLog from within MakeService.dyapp (but not MyApp.dyapp):

...
Load ..\AplTree\OS
Load ..\AplTree\WindowsEventLog
Load ..\AplTree\Logger
...

We need to add to the INI a flag that allows us to toggle writing to the Window Event Log:

...
[Ride]
Active      = 0
Port        = 4599
wait        = 1

[WindowsEventLog]
write       = 1 ; Has an affect only when it's running as a Service

Why would this be useful? During development, when you run the Service to see what it's doing, you might not want the application to write to your Windows Event Log, for example.

We modify the MyApp.CreateConfig function so that it creates Config.WriteToWindowsEventLog from that INI entry:

∇ Config←CreateConfig isService;myIni;iniFilename
...
      :If isService
          Config.WatchFolders←⊃myIni.Get'Folders:Watch'
          Config.WriteToWindowsEventLog←myIni.Get'WINDOWSEVENTLOG:write'
      :Else
          Config.LogFolder←'expand'F.NormalizePath⊃Config.LogFolder myIni.Get'Folders:Logs'
          Config.WriteToWindowsEventLog←0
      :EndIf
...
∇

For logging we introduce two new functions, Log and LogError. First Log:

∇ {r}←{both}Log msg
 ⍝ Writes to the application's log file only by default.
 ⍝ By specifying 'both' as left argument one can force the fns to write
 ⍝ `msg` also to the Windows Event Log if Config.WriteToWindowsEventLog.
   r←⍬
   both←(⊂{0<⎕NC ⍵:⍎⍵ ⋄ ''}'both')∊'both' 1
   :If 0<⎕NC'MyLogger'
       MyLogger.Log msg
   :EndIf
   :If both
   :AndIf Config.WriteToWindowsEventLog
       :Trap 0    ⍝ Don't allow logging to break!
           MyWinEventLog.WriteInfo msg
       :Else
           MyLogger.LogError'Writing to the Windows Event Log failed for:'
           MyLogger.LogError msg
       :EndTrap
   :EndIf
∇

Note that this function always writes to the application's log file. By specifying 'both' as left argument one can get the function to also write to the Windows Event Log, given that Config.WriteToWindowsEventLog is true.

That allows us to use Log for logging all events but errors, and to specify 'both' as left argument when we want the function to record the Service starting, pausing and stopping. In other words, all calls to MyLogger.Log will be replaced by Log, although some calls require 'both' to be passed as the left argument.

We also introduce a function LogError:

∇ {r}←LogError(rc msg)
 ⍝ Write to **both** the application's log file and the Windows Event Log.
   MyLogger.LogError msg
   :If Config.WriteToWindowsEventLog
       :Trap 0
           MyWinEventLog.WriteError msg
       :Else
           MyLogger.LogError'Could not write to the Windows Event Log:'
           MyLogger.LogError msg
       :EndTrap
   :EndIf
∇

Note that the Logger class traps any errors that occur. The WindowsEventClass does not do this, and the calls to WriteInfo and WriteError might fail for all sorts of reasons: invalid data type, invalid depth, lack of rights – you name it.

Therefore both Log and LogError trap any errors and write to the log file in case something goes wrong. Note also that in this particular case it's okay to trap all possible errors (0) because we cannot possibly foresee what might go wrong. In a real-world application you still want to be able to switch this kind of error trapping off via an INI entry etc.

In the case of an error we now want the function LogError to be called, so we change SetTrap accordingly:

∇ trap←{force}SetTrap Config
...
  #.ErrorParms.returnCode←EXIT.APPLICATION_CRASHED
  #.ErrorParms.(logFunctionParent logFunction)←⎕THIS'LogError'
  #.ErrorParms.windowsEventSource←'MyApp'
...
∇

Now it's time to replace the call to MyLogger.Log by a call to Log in the MyApp class; use the replace feature of the editor in order to achieve that.

There are however three functions where we need to add 'both' as left argument:

∇ {r}←MainLoop dummy;S
  r←⍬
  'both'Log'"MyApp" server started'
  S←#.ServiceState
  :Repeat
      LoopOverFolder ⍬
      :If ('both'∘Log S.CheckServiceMessages)S.IsRunningAsService
          'both'Log'"MyApp" is about to shut down...'
          :Leave
      :EndIf
      ⎕DL 2
  :Until 0
 ⍝Done
∇

Note that use the compose () operator here: only by ‘gluing’ the left argument ('both') to the function name with the compose operator can we ensure everything's passed to the Log function is written not only to the log file but also to the Windows Event Log when ServiceState is managing the communication between the SCM and the application.

The second function to be changed is Off:

    ∇ Off exitCode
      :If exitCode=EXIT.OK
          'both'Log'Shutting down MyApp'
      :Else

Now we change Initial: if the application is running as a service we let Initial create an instance of WindowsEventLog and return it as part of the result.

leanpub-start-insert
∇ r←Initial isService;parms;Config;MyLogger;MyWinEventLog
⍝ Prepares the application.
  Config←CreateConfig isService
  Config.ControlFileTieNo←CheckForOtherInstances ⍬
  CheckForRide(0≠Config.Ride)Config.Ride
  MyLogger←OpenLogFile Config.LogFolder
  Log'Started MyApp in ',F.PWD
  Log 2 ⎕NQ'#' 'GetCommandLine'
  Log↓⎕FMT Config.∆List
  r←Config MyLogger
  :If isService
      MyWinEventLog←⎕NEW #.WindowsEventLog(,⊂'MyAppService')
      parms←#.ServiceState.CreateParmSpace
      parms.logFunction←'Log'
      parms.logFunctionParent←⎕THIS
      #.ServiceState.Init parms
      r,←MyWinEventLog
  :EndIf
∇

Initial is called by RunAsService and StartFromCmdLine, but because the result of Initial remains unchanged if the application is not running as a Service we need to amend just RunAsService.

We localise MyWinEventLog (the name of the instance) and change the call to Initial since it now returns a three-item vector:

leanpub-start-insert
∇ {r}←RunAsService(earlyRide ridePort);⎕TRAP;MyLogger;Config;∆FileHashes;MyWinEventLog
 ⍝ Main function when app is running as a Windows Service.
...
  ⎕TRAP←#.HandleError.SetTrap ⍬
  (Config MyLogger MyWinEventLog)←Initial 1
  ⎕TRAP←(Config.Debug=0)SetTrap Config
...
∇

Having made all these changes we should check whether the basics still work:

  1. Double-click Make.bat in order to re-compile the EXE.
  2. Double-click MyApp.dyapp. This assembles the workspace, including the test cases.
  3. Answer with y the question whether all test cases shall be executed.

Ideally the test cases should pass.

Now it's time to run the test cases for the Service:

  1. Open a console window with admin rights.
  2. Navigate to the v13\ folder.
  3. Call MakeService.dyapp.
  4. Execute TestsForServices.GetHelpers.
  5. Call TestsForServices.RunDebug 0.

Now start the Event Viewer; you should see something like this:

The Windows Event Log

You might need to scroll down a bit.

We shall add a test case that checks whether the new logging feature works. For that we introduce Test_03:

∇ R←Test_03(stopFlag batchFlag);⎕TRAP;MyWinLog;noOfRecords;more;rc;records;buff
  ⍝ Start & stop the service, then check the Windows Event Log.
  ⎕TRAP←(999 'C' '. ⍝ Deliberate error')(0 'N')
  R←∆Failed

  MyWinLog←⎕NEW #.WindowsEventLog(,⊂'MyAppService')
  noOfRecords←MyWinLog.NumberOfLogEntries

  (rc more)←∆Execute_SC_Cmd'start'
  →FailsIf 0≠rc
  ∆Pause 1
  (rc more)←∆Execute_SC_Cmd'query'
  →FailsIf 0=∨/'STATE : 4 RUNNING'⍷#.APLTreeUtils.dmb more
  ∆Pause 2

  (rc more)←∆Execute_SC_Cmd'stop'
  →FailsIf 0≠rc
  ∆Pause 2

  records←(noOfRecords-10)+⍳(MyWinLog.NumberOfLogEntries+10)-noOfRecords
  buff←↑MyWinLog.ReadThese records
  →PassesIf∨/,'"MyApp" server started '⍷buff
  →PassesIf∨/,'Shutting down MyApp'⍷buff

  R←∆OK
∇

Notes:

  1. First we save the number of records currently saved in the Windows Event Log “Application”.
  2. We then start and stop the server to make sure we get some fresh records written.
  3. We then read the number of records plus 10 (others write to the Windows Event Log as well) and investigate them.

Feel confident with the Windows Event Log? Well, a few more wrinkles yet:


Footnotes

  1. Microsoft on the Windows Event Log:
    https://msdn.microsoft.com/en-us/library/windows/desktop/aa363648(v=vs.85).aspx

  2. Details about System Restore Point:
    https://en.wikipedia.org/wiki/System_Restore