Weird behavior with OnShutdown() event in a Windows Service

Question

I have developed a windows service in vb.net (VS2017, target .net framework 4.5).
The windows service do automatically sql-server backups (timer based), delete old backup files, read and write a .ini file and send emails in some situations and - of curse - write to the event log. The Service has to run on a windows server 2019 (standard).
Anything works as expected - except the handling of the OnShutdown() event, that drives me crazy, as it is a "moving target".
If the server is shut down (normal case should be "restart"), I want to:

• log in the event log
• write in a .ini
• send an email

My code zu OnShutdown():

Protected Overrides Sub OnShutdown()
  cModul = "OnShutdown()"
  ProtokollSchreiben("Der Server wird heruntergefahren...", Typ_Warning)
 '
  DebugProtokollSchreiben("Timer stoppen und anhalten...", Typ_Warning)
  MyTimer.Stop()
  MyTimer.Enabled = False
  DebugProtokollSchreiben("Timer gestoppt und angehalten...", Typ_Warning)
  DebugProtokollSchreiben("Der Server wird heruntergefahren...", Typ_Warning)
  DebugProtokollSchreiben("Vor schreiben .ini...", Typ_Warning)
  cIniFile.WriteInteger("WindowsService", "ServerWurdeGebooted", 1)
  DebugProtokollSchreiben("Nach schreiben .ini...", Typ_Warning)
  DebugProtokollSchreiben("Vor MailversandServerReboot...", Typ_Warning)
  MailversandServerReboot()
 cModul = "OnShutdown()"
  DebugProtokollSchreiben("Nach MailversandServerReboot...", Typ_Warning)
 '
   MyBase.OnShutdown()' call “original event”
End Sub

Notes:
I set:

Me.CanShutdown = True

in the designer code and write the actual value at startup in the event log (CanShutdown is set to true at runtime).
In ProtokollSchreiben() and DebugProtokollSchreiben() only log entries are written. In MailversandServerReboot() an email is sent over SMTP (this works in other parts of the service without problems).

Behavior:

• sometimes the event (OnShutdown() is called, sometimes not
• if it is called, mostly, the last event in the event log is "Vor schreiben .ini..." (= before write in the .ini file)
• -> whereby the .ini in this cases sometimes is updated (although the next log entry "Nach schreiben .ini..." is not written to the event log), sometimes not

I have searched the internet and read this SO-Links:
detect shutdown in window service
Windows Service does seem to do nothing OnShutdown()
Can a Windows Service take hours to shutdown gracefully?

As far, as I have seen, I should have about 20 Seconds time to do something in OnShutDown().
To write the event log and the .ini should not take a single second....
Maybe, to send the email (in function "MailversandServerReboot()") could take a longer time or maybe the email can't be sent as other (needed) services are down, when OnShutdown() is triggered...
But, I don't understand, that the event sometimes is called, sometimes not and if it is called, that mostly the entry "Nach schreiben .ini..." is not written to the event log.
Thanks for any hint :-)

Answer 1

First, thanks to @craig for the comment to my typo (in my first posting, I had my.OnShutdown() instead of MyBase.OnShutDown(). I have corrected this in my posting now (but this do not solve my problems). Thanks also to @CoreTech for the comment.
I seems, as I now have found a workaround for my needs...
I have queried the internet further and done a lot of "try-and-errors".
My personal findings (may be wrong):
It seems, as almost nothing is guaranteed in OnShutDown() event, as the System (Server and Services) goes down in a not clear defined order.
So... maybe entries in the event log can be written, maybe not. Maybe entries in an (custom) .ini can be written, maybe not.
By my tries, I never was able to send an email with SMTP in OnShutDown() (over a SMTP-server).
This would explain my weird (not to comprehend) problems ("moving target").
I simply want to know, when the server was shutdown and send an email, to inform the customer (and us) that (and when) the server was booted and that the windows service again is up and running.
And this only, if the sever really was booted (not by every start of the service:-).
So.. what I do now (seems to work -> tested about 20 times):

Protected Overrides Sub OnShutdown()
  cModul = "OnShutdown()"
' Write a Flag-File to the Server reboot including a timestamp
  Dim cZeitpunkt As String = System.DateTime.Now.ToShortDateString.ToString.ToString
  cZeitpunkt = cZeitpunkt + ", " + System.DateTime.Now.ToShortTimeString.ToString
  System.IO.File.WriteAllText(cFlagFileNameMitPfad, "Der Windows-Server zum SQL-Server 2019 (WPE) wurde heruntergefahren am: " + cZeitpunkt)
'
' Create an additional file in a sub directory to see, THAT the server was rebooted (also after the service was restarted an had deleted the file in the OnStart() event)
'
' Check if subdirectory exists -> if not -> create it
  If Not System.IO.Directory.Exists(cSaveFlagVerzeichnis) Then
    System.IO.Directory.CreateDirectory(cSaveFlagVerzeichnis)
  End If

‘ Generate DateTimeStamp for Filename (own function)
  Dim cFileTimeStamp As String = DateTime2StringFileName(System.DateTime.Now)
' Do some minor changes to the needed format (cut leading “_” and add it an the end)
  cFileTimeStamp = cFileTimeStamp.Substring(1, cFileTimeStamp.Length - 1) + "_"
  Dim cFlagFileNameSave As String = cSaveFlagVerzeichnis + "\" + cFileTimeStamp + cFlagFileName
' Write the additional file
 System.IO.File.WriteAllText(cFlagFileNameSave, "Der Windows-Server zum SQL-Server 2019 (WPE) wurde heruntergefahren am: " + cZeitpunkt)
'
' Write to the event log (note: it is not guaranteed, that the entries are written, but it’s only informative)
  ProtokollSchreiben("Der Server wird heruntergefahren, Flag-File wurde geschrieben..", Typ_Warning)
  DebugProtokollSchreiben("Der Server wird heruntergefahren, Flag-File wurde geschrieben..", Typ_Warning)
'
  MyBase.OnShutdown() ' Call original event
End Sub

Notes:
On startup I get the startup path (to the service). The "main flag file" is written to that directory. The "save flag files" are written in a subdirectory of the that directory (see also screenshot below).

To better comprehend: The "root directory" is \prog\ ( 1 ). In the sub directory \SaveRebootFlags\ ( 2 ) one flag file remains stored for every reboot.
Any file ( 3 ) contains a text with the timestamp to the server shutdown (not to the restart of the windows service) In the "root directory" \prog\ ( 1 ) a similar flag file is written,
but without the datetime stamp (only ( 4 ))... so this filename is always the same.
In OnStart() of the service, I check, if a flag file is stored in the "root directory" \Prog\ ( 1 ).
If yes, an email is sent "The server was down at 'timestamp in flag file', the windows service was restarted and works again...".
After sending the email, the "main flag file" is deleted automatically.
Note: As we have the files also in ( 2 ) we can comprehend any reboot.
This is not what I initially wanted, but it works (at least for me;-).
Maybe this helps somebody, that also is "stumbled" over a weird behavior...