HOW TO: Ready-To-Go Backup and Cleardown script

This section contains user-submitted tutorials.
palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-07-23 12:46

One more oddity to throw into the mix. After reviewing the log snippet in the post above, I noticed that the SQL file at the top of the list is the wrong one - the time is mismatched: the SQL file is from a previous backup, not the 3am scheduled one. However, when I look in the zip archive for the 3am backup, the correct (3am) SQL file is there. Weird.

Edit- in the bat file:

3rd is copy data dir
4th is mysql dump

So the log makes sense now. By the way, there is no entry in the log for mysqldump.
Last edited by palinka on 2018-07-23 13:13, edited 1 time in total.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-07-23 13:00

palinka wrote:
2018-07-23 12:24
Whoa... I just noticed this:

Image

It looks like the archive files are way too small. The 7z files are from the HMS-included backup script. The zips are from this script.

Any idea what that's about?
Its too late to edit the post, but...

I think I simply misunderstood something here. Please correct me if I'm wrong.

Code: Select all

rem ---  HOW MANY recent backup Zips do you want to retain?  ----
set DAYSZIPTOKEEP=5
I thought that meant how many days of backups to retain, but now I believe it's how many days of messages to retain within each backup. Is that correct? And if that's the case, to retain all messages, do I set the variable to 0 or just rem the entire line?

Edit- OK, I found my problem.

Code: Select all

rem ---  SET LOCATIONS (without trailing '\')  ----
Set BACKUPdir=X:\HMS-BACKUP
Set BACKUPTEMPdir=X:\HMS-BACKUP\Backup-Temp
Bad! Backuptempdir must be located outside backupdir or else the script deletes all messages older than daysziptokeep because it's running on all subfolders! :-)

Also, regarding the log not getting attached, could it be due to size? With my little screw up, many extra lines (deleting older than) were added to the log.

A little self help never hurt anyone. :-)

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-07-23 14:00

Post or send by pm the full log file if you still have problems.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-07-23 16:02

jimimaseye wrote:
2018-07-23 14:00
Post or send by pm the full log file if you still have problems.
One little tidbit I added to the script (that I believe originally came from you anyway). I already had an SA-update script that also renamed the SA log with a date, so I had a log for each day. I ran the script at 11:59 pm to capture the entire day and rename the log with that day's date.

Code: Select all

set hr=%time:~0,2%
if "%hr:~0,1%" equ " " set hr=0%hr:~1,1%
ren "C:\Program Files (x86)\hMailServer\Logs\spamd.log" spamd-%date:~-4,4%-%date:~-10,2%-%date:~-7,2%.log"
Added below as such:

Code: Select all

@rem Update Spamassassin before restarting service
if "%FailedSAService%" == "Failed to stop" goto 3rd
echo %time% Performing Spamassassin Update check...>> %BackLog%
set FailedSAUpdate=Ok
cd /D "%SPAMASSASSINdir%"
sa-update.exe -v --nogpg --channelfile UpdateChannels.txt >> %BackLog%
set hr=%time:~0,2%
if "%hr:~0,1%" equ " " set hr=0%hr:~1,1%
ren "C:\Program Files (x86)\hMailServer\Logs\spamd.log" spamd-%date:~-4,4%-%date:~-10,2%-%date:~-7,2%.log"
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedSAUpdate=Failed&set bold=b&set fontcolor=%colorfill%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Spam Assassin Def Update:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedSAUpdate%^</td^>^</tr^> >>%outf%
Then deleted the SA update scheduled task as its now a duplicate task and I changed the backupmail scheduled task to run at 11:59pm so the SA log rolls per day as before.

~~~~~~~~~~~

Still having the issue of the log file not being attached. I looked at the message source and it appears to be there, but its not showing as an attachment in either Nine for android, rainloop webmail or outlook 2016. Here's the entire message:

Code: Select all

Return-Path: system@DOMAIN1.TLD
X-Spam-Checker-Version: SpamAssassin 3.4.1 (2015-04-28) on BrianServer
X-Spam-Level: 
X-Spam-Status: No, score=-1.0 required=5.0 tests=ALL_TRUSTED,HTML_MESSAGE autolearn=ham
 autolearn_force=no version=3.4.1
X-Spam-Report: * -1.0 ALL_TRUSTED Passed through trusted hosts only via SMTP *  0.0
 HTML_MESSAGE BODY: HTML included in message * //t
Received: from brianserver (BrianServer [127.0.0.1]) by [REDACTED] with ESMTP ; Mon,
 23 Jul 2018 07:55:52 -0400
Date: Mon, 23 Jul 2018 07:55:52 -0400
From: Backup Daemon <system@DOMAIN1.TLD>
To: admin@123.dynu.com
X-Mailer: Blat v3.2.19, a Win32 SMTP/NNTP mailer http://www.blat.net
Message-ID: <01d4227c$Blat.v3.2.19$1acd6ac7$b08c413add0@localhost>
Subject: Backup completed. See attachment log file.
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="=_BlatBoundary-hZwBmS226umyRVbpwHB00"
oclient: 127.0.0.1##25

This is a multi-part message in MIME format.

--=_BlatBoundary-hZwBmS226umyRVbpwHB00
Content-Description: Mail message body
Content-Transfer-Encoding: 7BIT
Content-Type: text/html; charset="ISO-8859-1"

<table border='0'> 
<tr><td><!--><!-->Hmailserver service shutdown:</td><td><!--><!-->Ok</td></tr> 
<tr><td><!--><!-->Spamassassin service shutdown:</td><td><!--><!-->Ok</td></tr> 
<tr><td><!--><!-->Spam Assassin Def Update:</td><td><!--><!-->Ok</td></tr> 
<tr><td><!--><!-->Spam Assassin Service startup: </td><td><!--><!-->Ok</td></tr> 
<tr><td><!--><!-->Hmailserver service startup:</td><td><!--><!-->Ok</td></tr> 
<tr><td><!--><!-->Zip:</td><td><!--><!-->Ok</td></tr> 
<tr><td><!--><!-->Email Cleardown Script: </td><td><!--><!-->Ok</td></tr> 
<tr><td><br></td></tr></table>See attached log file below for details. 

--=_BlatBoundary-hZwBmS226umyRVbpwHB00
Content-Type: text/plain; charset="ISO-8859-1"
Content-Transfer-Encoding: 7BIT
Content-Disposition: INLINE
Content-Description: "Backup_2018-07-23-075256.log"

Backup Start: Mon 07/23/2018  7:52:56.21 
 7:52:56.23 Stopping Hmailserver service...

The hMailServer service was stopped successfully.

Ok! 
 7:52:57.24 Stopping Spamassassin service...
..
The spamassassin service was stopped successfully.

Ok! 
 7:53:02.32 Performing Spamassassin Update check...

-------------------------------------------------------------------------------
   ROBOCOPY     ::     Robust File Copy for Windows                              
-------------------------------------------------------------------------------

  Started : Monday, July 23, 2018 7:53:02 AM
   Source : X:\HMS-DATA\
     Dest : X:\HMS-BACKUP-TEMP\hMailData\

    Files : *.*
	    
  Options : *.* /NDL /S /E /DCOPY:DA /COPY:DAT /PURGE /MIR /NP /R:43200 /W:1 

------------------------------------------------------------------------------

	  *EXTRA File 		   8.8 m	X:\HMS-BACKUP-TEMP\hMailData\MYSQLDump_2018-07-23-073304.mysql
	    New File  		    8221	X:\HMS-DATA\Data\domain1.tld\admin\32\{32CDAA9E-F96E-48E3-BD05-A2D29DFAA406}.eml
	    New File  		   1.0 m	X:\HMS-DATA\Data\domain1.tld\admin\AA\{AAF80DEA-92AD-4605-B1A7-2D4725F0459A}.eml
	  *EXTRA File 		   41488	X:\HMS-BACKUP-TEMP\hMailData\Data\domain2.tld\barb\63\{630442A2-F672-4D33-A06C-07B8A8406542}.eml
	    New File  		    1344	X:\HMS-DATA\Data\domain2.tld\barb\C8\{C81C2360-6A11-45DA-BFB1-56CF7960E147}.eml
	  *EXTRA File 		     908	X:\HMS-BACKUP-TEMP\hMailData\Data\domain2.tld\barb\F2\{F257E286-E8AE-4A6C-8F30-0E38229AC1C9}.eml
	  *EXTRA File 		   41392	X:\HMS-BACKUP-TEMP\hMailData\Data\domain2.tld\ed\D1\{D1953A72-98F1-49A8-8670-63E00E6308B6}.eml
	  *EXTRA File 		  110888	X:\HMS-BACKUP-TEMP\hMailData\Data\domain2.tld\ed\DF\{DFA86288-BEB5-4433-BF3E-6F21E7AA0342}.eml

------------------------------------------------------------------------------

               Total    Copied   Skipped  Mismatch    FAILED    Extras
    Dirs :      4026         0      4026         0         0         0
   Files :     10146         3     10143         0         0         5
   Bytes :   1.472 g    1.05 m   1.471 g         0         0    9.05 m
   Times :   0:00:01   0:00:00                       0:00:00   0:00:01
   Ended : Monday, July 23, 2018 7:53:04 AM

OKCOPY + XTRA  
 7:53:09.46 Starting Spamassassin service...
The spamassassin service is starting.
The spamassassin service was started successfully.

Ok! 
 7:53:11.54 Starting Hmailserver service... 
The hMailServer service is starting.
The hMailServer service was started successfully.

Ok! Errorlevel=0 
Mon 07/23/2018  7:53:13.77 7Zip Creating archive X:\HMS-BACKUP\Serverdata_2018-07-23-075256.zip 
 
Email clear up started at  7:55:48.54 ************************************ 
Removed 0 message(s) from Trash folder in account a@domain1.tld

Deleted* folder Not Found in account a@domain1.tld
Removed 0 message(s) from Spam folder in account a@domain1.tld

~~~~~~~SNIP~~~~~~~

Deleted* folder Not Found in account notify@DOMAIN3.TLD
Spam folder Not Found in account notify@DOMAIN3.TLD
Email clear up finished at  7:55:51.92 (errorlevel: 0) **********************

Created: "X:\HMS-BACKUP\Serverdata_2018-07-23-075256.zip" 943708403
Mon 07/23/2018  7:55:51.93 Backup 7Zip Archive created - no errors encountered. 

--=_BlatBoundary-hZwBmS226umyRVbpwHB00--
And the emailer log:

Code: Select all

2018.07.23 07:55:52 (Mon)------------Start of Session-----------------
Blat v3.2.19 (build : Nov 18 2017 03:14:35)
32-bit Windows, Full, Unicode
Sending C:\scripts\HMSBackupCleardown\\body.html to admin@DOMAIN1.TLD
Subject: Backup completed. See attachment log file.
Login name is Backup Daemon <system@DOMAIN1.TLD>
Attached text file: X:\HMS-BACKUP\Backup_2018-07-23-075256.log
2018.07.23 07:55:53 (Mon)-------------End of Session------------------
********************************** 
Looks like it has something to do with blat.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-07-23 16:14

Maybe this has something to do with it:
"%BLATdir%" %outf% -mailfrom %emailFrom% -to %emailRecipient% -subject %resulttext% -server localhost -attachi %BackLog% -log %emailer_log%
-attachi is for inline attachments but I believe the fact that the message is html format is preventing the inline attachment from being rendered in the message?? I'll try -attacht first, and failing that, -attach.

EDIT: -attach works. I did not try -attacht. Log is now attached as filename.log and opens in Nine for android attachment viewer.

I think that's all there is. Everything is working as intended. Great script. Thanks again!

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-07-23 21:25

palinka wrote:
2018-07-23 16:14
Maybe this has something to do with it:
"%BLATdir%" %outf% -mailfrom %emailFrom% -to %emailRecipient% -subject %resulttext% -server localhost -attachi %BackLog% -log %emailer_log%
-attachi is for inline attachments but I believe the fact that the message is html format is preventing the inline attachment from being rendered in the message?? I'll try -attacht first, and failing that, -attach.

EDIT: -attach works. I did not try -attacht. Log is now attached as filename.log and opens in Nine for android attachment viewer.

I think that's all there is. Everything is working as intended. Great script. Thanks again!
-attachi works for me (and I expect many others that have used the script as is). I suspect, however, that the choice of email client and its configuration determines how 'inline' html attachments are handled (or not). I use Thunderbird and K9 (android) mainly. Im glad you found the cause and the solution for you, it might help others with similar situations.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-07-23 21:38

jimimaseye wrote:
2018-07-23 21:25
-attachi works for me (and I expect many others that have used the script as is). I suspect, however, that the choice of email client and its configuration determines how 'inline' html attachments are handled (or not). I use Thunderbird and K9 (android) mainly. Im glad you found the cause and the solution for you, it might help others with similar situations.
Here's what I've tried with respect to -attachi

Outlook 2016 - no worky
Nine for Android - no worky
Rainloop Webmail - no worky
Roundcube Webmail - SUCCESS
Horde Webmail - SUCCESS
Windows 10 Mail App - no worky

I don't have any other clients to try it on.

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-07-23 21:47

palinka wrote:
2018-07-23 21:38
"no worky"
:lol: :mrgreen:
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-07-23 22:19

palinka wrote:
2018-07-23 16:14
Maybe this has something to do with it:
"%BLATdir%" %outf% -mailfrom %emailFrom% -to %emailRecipient% -subject %resulttext% -server localhost -attachi %BackLog% -log %emailer_log%
-attachi is for inline attachments but I believe the fact that the message is html format is preventing the inline attachment from being rendered in the message?? I'll try -attacht first, and failing that, -attach.

EDIT: -attach works. I did not try -attacht. Log is now attached as filename.log and opens in Nine for android attachment viewer.
My reasons for using INLINE (-attachi)

Untitled.png

The above is as it displays in Thunderbird. (This does the same for my android K9 mail app too)

Due to displaying the log contents in the message itself, it saves on having to launch attachments with other apps (simply scroll through the email message to read the log).
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-07-24 00:43

I totally agree, except for the fact that the email clients I use don't render the attachment. Maybe I'll play around with the script to produce a text-only message, which should cure the inline attachment issue for me.

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-07-24 01:19

palinka wrote:
2018-07-24 00:43
I totally agree, except for the fact that the email clients I use don't render the attachment. Maybe I'll play around with the script to produce a text-only message, which should cure the inline attachment issue for me.
Text only is simple enough to do. I opted for html version in order to use colour and bold formatting (and easy tab/cell spacing).
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-08-12 18:05

jimimaseye wrote:
2018-07-24 01:19
palinka wrote:
2018-07-24 00:43
I totally agree, except for the fact that the email clients I use don't render the attachment. Maybe I'll play around with the script to produce a text-only message, which should cure the inline attachment issue for me.
Text only is simple enough to do. I opted for html version in order to use colour and bold formatting (and easy tab/cell spacing).
So I went through the script and removed all the html stuff and changed -attach to -attachi but it made no difference. I guess its totally dependent on the client. In this case, I only tried Nine for android and outlook 2016.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-08 12:56

For 2 days in a row, I had this error:

Backup Start: Fri 09/07/2018 23:58:00.93
23:58:00.95 Stopping Hmailserver service...
Failed to stop. Backup of emails not performed!!

Yesterday morning when I got the email with the error, I didn't think much of it and figured it was just a windows ghost in the machine so I rebooted the computer. Then I got the error again this morning, making it two days in a row. I looked in the event log and found this:

A timeout (30000 milliseconds) was reached while waiting for a transaction response from the hMailServer service.

Then I went to task scheduler and ran it manually and it was successful.

Any idea what could be causing this? Or maybe is there a way to increase the timeout?

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-09-08 13:19

I also get these occasionally (rarely) and also (more often) delays Iin starting it again. This is why i made the change to the script that checks the service is up and running when it gets to the end (emailing the log).

It is a windows thing as you have identified. I often find it happens when there are some windows updates waiting to be installed or awaiting for a consequential update reboot.

I don't think the timeout value is changeable. I don't know how to change it (there is a reason why Microsoft have a service 'retry' parameter for failures to restart) but it is so rare that I remain mindful of it and just deal with it as it happens.

Perhaps you might want to experiment and script in a PAUSE of the service (using the ComAPI) prior to shutting it down.

[Entered by mobile. Excuse my spelling.]


EDIT: interesting for you: viewtopic.php?t=23679

EDIT2:
SERVERSTATUSREPORT.VBS

Code: Select all

  Set oApp = CreateObject("hMailServer.Application")
   Call oApp.Authenticate("Administrator", "yoursecretpassword" )
   
   wscript.echo vbCrLf
   wscript.echo "HMS Server Start Time: " & oApp.status.StartTime
   wscript.echo "HMS Daily Spam Reject count: " & oApp.status.RemovedSpamMessages
   wscript.echo "HMS Daily Viruses Removed count: " & oApp.status.RemovedViruses & vbCrLf
   oApp.stop
Change BackupMail.bat to read:

Code: Select all

echo Backup Start: %date% %time% > %BackLog%

cscript C:\pathto\ServerStatusBlockReport.vbs //nologo //T:600   >> %BackLog%

REM :: Perform backup to temporary directory

:1st
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-08 16:30

I read the thread you posted. It seems mostly geared toward a bug present in that older build.

I run the backup at 11:58 pm for a couple of reasons, but mostly so the logs begin at/after midnight. Below are the end of yesterday's log (showing shutdown) and the beginning of today's log (showing startup). It appears that one thread hung up the process but only 12 seconds and then "Given up waiting for threads to join in queue Server queue." Looking at the log, its apparent that it did not finish shutting down. However, the other strange thing is that there are no log entries for about 4 minutes.

When I compared this morning's successful (manual) run to the unsuccessful run last night, I see that after stopping, there is only 22 seconds between log entries (end of shutdown to beginning of startup).

Thanks for the vbs - I'm putting that in right now. But I think I'll wait a couple of days to see what happens before setting up the pause script. I have a stair rail to fix today. :mrgreen:

edit - foogotz de logz…. :oops:

Code: Select all

****** Below from end of yesterday's hmailserver log ******

"DEBUG"	4696	"2018-09-07 23:58:01.077"	"Received stop-request from Windows."
"APPLICATION"	4696	"2018-09-07 23:58:01.077"	"Stopping servers..."
"DEBUG"	4696	"2018-09-07 23:58:01.077"	"Application::StopServers() - Removing server work queue"
"DEBUG"	4696	"2018-09-07 23:58:01.077"	"WorkQueueManager::RemoveQueue - Server queue"
"DEBUG"	4696	"2018-09-07 23:58:01.077"	"Stopping working queue Server queue."
"DEBUG"	4696	"2018-09-07 23:58:01.077"	"Interupt and join threads in working queue Server queue"
"DEBUG"	5168	"2018-09-07 23:58:01.093"	"Worker exited in work queue Server queue"
"DEBUG"	5172	"2018-09-07 23:58:01.093"	"IOService::Stop()"
"DEBUG"	5176	"2018-09-07 23:58:01.093"	"Worker exited in work queue Server queue"
"DEBUG"	5180	"2018-09-07 23:58:01.093"	"Worker exited in work queue Server queue"
"DEBUG"	5368	"2018-09-07 23:58:01.093"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5380	"2018-09-07 23:58:01.093"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5396	"2018-09-07 23:58:01.093"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5384	"2018-09-07 23:58:01.093"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5392	"2018-09-07 23:58:01.093"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5356	"2018-09-07 23:58:01.093"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5348	"2018-09-07 23:58:01.093"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5172	"2018-09-07 23:58:01.093"	"IOService::DoWork() - removing Queue IOCP Queue"
"DEBUG"	4696	"2018-09-07 23:58:01.093"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5368	"2018-09-07 23:58:01.093"	"Ending session 4462"
"DEBUG"	5380	"2018-09-07 23:58:01.093"	"Ending session 4375"
"DEBUG"	5396	"2018-09-07 23:58:01.093"	"Ending session 4450"
"DEBUG"	5384	"2018-09-07 23:58:01.093"	"Ending session 4280"
"DEBUG"	5392	"2018-09-07 23:58:01.093"	"Ending session 4279"
"DEBUG"	5356	"2018-09-07 23:58:01.093"	"Ending session 4423"
"DEBUG"	5348	"2018-09-07 23:58:01.093"	"Ending session 4417"
"DEBUG"	5172	"2018-09-07 23:58:01.093"	"WorkQueueManager::RemoveQueue - IOCPQueue"
"DEBUG"	5172	"2018-09-07 23:58:01.108"	"Stopping working queue IOCPQueue."
"DEBUG"	5348	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5356	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5392	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5384	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5396	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5380	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5368	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5172	"2018-09-07 23:58:01.108"	"Interupt and join threads in working queue IOCPQueue"
"DEBUG"	5340	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5372	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5364	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5376	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5352	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5388	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5344	"2018-09-07 23:58:01.108"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5172	"2018-09-07 23:58:01.140"	"Still 2 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:01.374"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:01.421"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:01.655"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:01.702"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:01.936"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:01.983"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:02.218"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:02.265"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:02.499"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:02.546"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:02.780"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:02.827"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:03.061"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:03.108"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:03.343"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:03.390"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:03.624"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:03.671"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:03.905"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:03.952"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:04.186"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:04.233"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:04.468"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:04.515"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:04.749"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:04.796"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:05.030"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:05.077"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:05.311"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:05.358"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:05.593"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:05.640"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:05.874"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:05.921"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:06.155"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:06.202"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:06.436"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:06.483"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:06.718"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:06.765"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:06.999"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:07.046"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:07.280"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:07.327"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:07.561"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:07.608"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:07.843"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:07.890"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:08.124"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:08.171"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:08.405"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:08.452"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:08.686"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:08.733"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:08.968"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:09.015"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:09.249"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:09.296"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:09.530"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:09.577"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:09.811"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:09.858"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:10.093"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:10.140"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:10.374"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:10.421"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:10.655"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:10.702"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:10.936"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:10.983"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:11.218"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:11.265"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:11.499"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:11.546"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:11.780"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:11.827"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:12.061"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5172	"2018-09-07 23:58:12.108"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	4696	"2018-09-07 23:58:12.327"	"Given up waiting for threads to join in queue Server queue."
"DEBUG"	4696	"2018-09-07 23:58:12.327"	"WorkQueueManager::RemoveQueue - Stopped Server queue"
"DEBUG"	4696	"2018-09-07 23:58:12.327"	"WorkQueueManager::RemoveQueue - Erased Server queue"
"DEBUG"	4696	"2018-09-07 23:58:12.327"	"Destructing work queue Server queue"
"DEBUG"	5172	"2018-09-07 23:58:12.374"	"Given up waiting for threads to join in queue IOCPQueue."
"DEBUG"	5172	"2018-09-07 23:58:12.374"	"WorkQueueManager::RemoveQueue - Stopped IOCPQueue"
"DEBUG"	5172	"2018-09-07 23:58:12.374"	"WorkQueueManager::RemoveQueue - Erased IOCPQueue"
"DEBUG"	5172	"2018-09-07 23:58:12.374"	"IOService::Stop() - Complete"
"DEBUG"	5172	"2018-09-07 23:58:12.374"	"Destructing work queue IOCPQueue"
"DEBUG"	5296	"2018-09-07 23:58:16.858"	"No messages to index."
"DEBUG"	5360	"2018-09-07 23:58:20.780"	"Event completed"
"DEBUG"	5360	"2018-09-07 23:58:20.780"	"Ending session 4461"

****** END of yesterday's hmailserver log ******

****** Below from beginning of today's hmailserver log ******

"DEBUG"	6052	"2018-09-08 00:02:18.764"	"Application::InitInstance - Configuration loaded."
"DEBUG"	6052	"2018-09-08 00:02:18.764"	"Creating work queue Asynchronous task queue"
"DEBUG"	6052	"2018-09-08 00:02:18.764"	"Starting work queue Asynchronous task queue"
"DEBUG"	6000	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	6052	"2018-09-08 00:02:18.764"	"Started work queue Asynchronous task queue"
"DEBUG"	10004	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	3988	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	11996	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	2964	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	5752	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	9364	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	808	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	5416	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	10900	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	10896	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	12212	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	12240	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	11384	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	4424	"2018-09-08 00:02:18.764"	"Running worker in work queue Asynchronous task queue"
"APPLICATION"	6052	"2018-09-08 00:02:18.764"	"Starting servers..."
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Creating work queue Server queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Starting work queue Server queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Started work queue Server queue"
"DEBUG"	11392	"2018-09-08 00:02:19.201"	"Running worker in work queue Server queue"
"DEBUG"	8900	"2018-09-08 00:02:19.201"	"Running worker in work queue Server queue"
"DEBUG"	11436	"2018-09-08 00:02:19.201"	"Running worker in work queue Server queue"
"DEBUG"	12180	"2018-09-08 00:02:19.201"	"Running worker in work queue Server queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Adding task Scheduler to work queue Server queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Adding task IOService to work queue Server queue"
"DEBUG"	12180	"2018-09-08 00:02:19.201"	"Executing task Scheduler in work queue Server queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Creating work queue SMTP delivery queue"
"DEBUG"	11436	"2018-09-08 00:02:19.201"	"Executing task IOService in work queue Server queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Starting work queue SMTP delivery queue"
"DEBUG"	11436	"2018-09-08 00:02:19.201"	"IOService::Start()"
"DEBUG"	1212	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Started work queue SMTP delivery queue"
"DEBUG"	10184	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	10092	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	11604	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	2980	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	9520	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	11328	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	9516	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	5956	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	11556	"2018-09-08 00:02:19.201"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	6052	"2018-09-08 00:02:19.201"	"Adding task SMTPDeliveryManager to work queue Server queue"
"DEBUG"	11436	"2018-09-08 00:02:19.217"	"Creating session 1"
"DEBUG"	6052	"2018-09-08 00:02:19.217"	"Creating work queue External fetch queue"
"DEBUG"	6052	"2018-09-08 00:02:19.217"	"Starting work queue External fetch queue"
"DEBUG"	8900	"2018-09-08 00:02:19.217"	"Executing task SMTPDeliveryManager in work queue Server queue"
"DEBUG"	11436	"2018-09-08 00:02:19.217"	"Creating session 2"
"DEBUG"	8220	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	8288	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	10444	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	6052	"2018-09-08 00:02:19.217"	"Started work queue External fetch queue"
"DEBUG"	10624	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	5664	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	10616	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	1012	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	12044	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	9852	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	7392	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	9848	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	8580	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	5616	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	3808	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	6204	"2018-09-08 00:02:19.217"	"Running worker in work queue External fetch queue"
"DEBUG"	8900	"2018-09-08 00:02:19.217"	"SMTPDeliveryManager::Start()"
"DEBUG"	11436	"2018-09-08 00:02:19.217"	"Creating session 3"
"DEBUG"	6052	"2018-09-08 00:02:19.233"	"Adding task ExternalFetchManager to work queue Server queue"
"DEBUG"	6052	"2018-09-08 00:02:19.233"	"Starting message indexer..."
"DEBUG"	11392	"2018-09-08 00:02:19.233"	"Executing task ExternalFetchManager in work queue Server queue"
"DEBUG"	11436	"2018-09-08 00:02:19.233"	"Creating session 4"
"DEBUG"	10192	"2018-09-08 00:02:19.233"	"Message indexer started..."
"DEBUG"	11392	"2018-09-08 00:02:19.248"	"ExternalFetchManager::Start()"
"APPLICATION"	6052	"2018-09-08 00:02:19.248"	"Servers started."
"DEBUG"	11436	"2018-09-08 00:02:19.248"	"Creating session 5"
"DEBUG"	11436	"2018-09-08 00:02:19.248"	"Creating session 6"
"DEBUG"	11436	"2018-09-08 00:02:19.248"	"Creating session 7"
"DEBUG"	11436	"2018-09-08 00:02:19.248"	"Creating work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.248"	"Starting work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.248"	"Started work queue IOCPQueue"
"DEBUG"	392	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	9172	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	9936	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	11204	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	3344	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	10436	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	10072	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	9112	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	10880	"2018-09-08 00:02:19.248"	"Running worker in work queue IOCPQueue"
"DEBUG"	9876	"2018-09-08 00:02:19.264"	"Running worker in work queue IOCPQueue"
"DEBUG"	10508	"2018-09-08 00:02:19.264"	"Running worker in work queue IOCPQueue"
"DEBUG"	6300	"2018-09-08 00:02:19.264"	"Running worker in work queue IOCPQueue"
"DEBUG"	11944	"2018-09-08 00:02:19.264"	"Running worker in work queue IOCPQueue"
"DEBUG"	12128	"2018-09-08 00:02:19.264"	"Running worker in work queue IOCPQueue"
"DEBUG"	9468	"2018-09-08 00:02:19.264"	"Running worker in work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.264"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.280"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.280"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	9468	"2018-09-08 00:02:19.280"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	12128	"2018-09-08 00:02:19.280"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.280"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11944	"2018-09-08 00:02:19.280"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.280"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.280"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	6300	"2018-09-08 00:02:19.280"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	10508	"2018-09-08 00:02:19.280"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	9876	"2018-09-08 00:02:19.295"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	10880	"2018-09-08 00:02:19.295"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	9112	"2018-09-08 00:02:19.295"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	10072	"2018-09-08 00:02:19.295"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	11436	"2018-09-08 00:02:19.295"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	10436	"2018-09-08 00:02:19.311"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	3344	"2018-09-08 00:02:19.311"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	11204	"2018-09-08 00:02:19.311"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	9936	"2018-09-08 00:02:19.311"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	9172	"2018-09-08 00:02:19.311"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	392	"2018-09-08 00:02:19.311"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	10192	"2018-09-08 00:02:19.545"	"No messages to index."
"DEBUG"	8452	"2018-09-08 00:02:19.858"	"Reading messages from database."
"DEBUG"	8452	"2018-09-08 00:02:19.858"	"Deleting message"
"DEBUG"	8452	"2018-09-08 00:02:19.873"	"Deleting message file."
"DEBUG"	8452	"2018-09-08 00:02:20.170"	"Reading messages from database."
"DEBUG"	8452	"2018-09-08 00:02:20.186"	"Deleting message"
"DEBUG"	8452	"2018-09-08 00:02:20.186"	"Deleting message file."
"DEBUG"	8452	"2018-09-08 00:02:20.326"	"Reading messages from database."

^^^ cleardown script doing its job.... :)

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-09 12:58

Matt graciously provided a vb script to pause and unpause HMS in another thread.

Code: Select all

Option Explicit

Private const g_sAdminPassword = "Top_Secret_Password"

Dim oApp
Set oApp = CreateObject("hMailServer.Application")
' Give this script permission to access all
' hMailServer settings.
Call oApp.Authenticate("Administrator", g_sAdminPassword)

Call oApp.Stop
Wait(5)
Call oApp.Start

Function Wait(sec)
	Dim t
	t = Timer
	Do While ((Timer - t) < sec) Xor (Timer < t)
	Loop
End Function
I guess to integrate it, I would need 2 versions - one for stop and one for start - and get rid of the wait function.

Then to integrate it into the backup script, it would be something like this.

Code: Select all

:1st
:maildata
echo %time% Stopping Hmailserver service...>> %BackLog%&cscript C:\pathto\pause_hmailserver.vbs //nologo //T:20  >> %BackLog%
set FailedHmailservice=Ok
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedHmailservice=Failed to stop. Backup of emails not performed!&set bold=b&set fontcolor=%colorfill%
echo %FailedHmailservice%! >> %BackLog%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Hmailserver service shutdown:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedHmailservice%^</td^>^</tr^> >>%outf%
Can I simply replace "net stop hmailserver" with "cscript C:\pathto\ServerStatusBlockReport.vbs //nologo //T:20”?

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-09-09 13:15

No.

Youre making things too complicated.

My previous post already includes the 'pause' (before ultimately stopping) the server (It already include the oApp.Stop.)

You dont need to 'oApp.start' it again because it will automatically start when you restart the service later on. And if you do not physically stop the service you will have other issues (for example, with Atuo-reply caches not being reset/cleaned out)

Follow my last post as written under "EDIT2" - it achieves what you are asking for.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-09 13:19

And i just discovered something interesting. I looked in the backup folder and found backups for the 2 times that HMS failed to stop. They appear to be complete backups by size and also by looking in the zip file. I checked the logs to make sure I wasn't looking at the wrong zip file and sure enough, the log said failed to stop, no robocopy, etc. But the backup went through anyway. I guess it did a live backup and there's nothing in the script to tell it to skip the backup for failure of stopping the service?

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-09 13:21

jimimaseye wrote:
2018-09-09 13:15
No.

Youre making things too complicated.

My previous post already includes the 'pause' (before ultimately stopping) the server (It already include the oApp.Stop.)

You dont need to 'oApp.start' it again because it will automatically start when you restart the service later on. And if you do not physically stop the service you will have other issues (for example, with Atuo-reply caches not being reset/cleaned out)

Follow my last post as written under "EDIT2" - it achieves what you are asking for.
Ah. I'll have a closer look. Doing this from my phone sometimes I miss things. :mrgreen:

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-09-09 13:22

palinka wrote:
2018-09-09 13:19
I checked the logs to make sure I wasn't looking at the wrong zip file and sure enough, the log said failed to stop, no robocopy, etc. But the backup went through anyway.
Can you post the log file please.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-09 13:33

jimimaseye wrote:
2018-09-09 13:22
palinka wrote:
2018-09-09 13:19
I checked the logs to make sure I wasn't looking at the wrong zip file and sure enough, the log said failed to stop, no robocopy, etc. But the backup went through anyway.
Can you post the log file please.
I will as soon as I can sit down at my laptop.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-09 13:39

jimimaseye wrote:
2018-09-08 13:19

EDIT2:
SERVERSTATUSREPORT.VBS

Code: Select all

  Set oApp = CreateObject("hMailServer.Application")
   Call oApp.Authenticate("Administrator", "yoursecretpassword" )
   
   wscript.echo vbCrLf
   wscript.echo "HMS Server Start Time: " & oApp.status.StartTime
   wscript.echo "HMS Daily Spam Reject count: " & oApp.status.RemovedSpamMessages
   wscript.echo "HMS Daily Viruses Removed count: " & oApp.status.RemovedViruses & vbCrLf
   oApp.stop
Ah... See, this is my blind spot: I focused totally on the report aspects and didn't even notice the oApp.stop. :oops:

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-09 13:58

Log file for one of the 2 days where net stop hmailserver failed.

Code: Select all

Backup Start: Thu 09/06/2018 23:58:01.45 
23:58:01.47 Stopping Hmailserver service...
Failed to stop. Backup of emails not performed!! 
23:58:20.49 Stopping Spamassassin service...
.
The spamassassin service was stopped successfully.

Ok! 
23:58:23.03 Performing Spamassassin Update check...
23:58:23.44 Starting Spamassassin service...
The spamassassin service is starting.
The spamassassin service was started successfully.

Ok! 

Deleting over 5 days...."X:\HMS-BACKUP\Backup_2018-08-31-235801.log" 
Deleting over 5 days...."X:\HMS-BACKUP\Serverdata_2018-08-31-235801.zip" 
Thu 09/06/2018 23:58:25.69 7Zip Creating archive X:\HMS-BACKUP\Serverdata_2018-09-06-235801.zip 
 
Email clear up started at  0:01:40.47 ************************************ 
Removed 0 message(s) from Trash folder in account a@mydomain.tld

Deleted* folder Not Found in account a@mydomain.tld
Junk* folder Not Found in account a@mydomain.tld
Removed 0 message(s) from Spam folder in account a@mydomain.tld

*** [SNIP - CLEARUP SCRIPT RAN SUCCESSFULLY] ***

Email clear up finished at  0:01:52.58 (errorlevel: 0) **********************

Created: "X:\HMS-BACKUP\Serverdata_2018-09-06-235801.zip" 1177048697
Fri 09/07/2018  0:01:52.59 Backup procedure FAILED!!! Zip: Ok, Script: Ok, SA Update: Ok, SA Service: Ok, Hmailserver service: Failed to stop. Backup of emails not performed!. 
2018-09-09 (2).png

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-09-09 14:03

Remember that the Hmailserver service failure to stop doesnt stop the rest of the backup procedure from continuing - it just prevents the UPDATE of the temporary backup directory of the email files (and matching database dump). Consequently, the ZIP file that is created will still take the existing (not updated) contents of the temporary backup directory emails (ie, the same contents as the previous day). Thats why it will still look like a full backup. It is important to complete like this as you might have other directories and data files in your backup script that are updated (under 7th 8th etc. For example, I also backup the SAGE accounting data directory that is on the same server.)
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-09-09 14:07

Yes, I see now that the file sizes of the 2 consecutive failures are the same as the day before.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-01 11:52

Today, my log file was 100 times larger than normal. It wouldn't even open on my phone as an attachment as I normally look at it in the morning. I thought I might have been hacked, but there's nothing in the queue and everything else looks normal. Finally I looked at the log on my laptop and found 14,000 lines of this:

Code: Select all

-------------------------------------------------------------------------------
   ROBOCOPY     ::     Robust File Copy for Windows                              
-------------------------------------------------------------------------------

  Started : Sunday, September 30, 2018 11:58:21 PM
   Source : X:\HMS-DATA\
     Dest : X:\HMS-BACKUP-TEMP\hMailData\

    Files : *.*
	    
  Options : *.* /NDL /S /E /DCOPY:DA /COPY:DAT /PURGE /MIR /NP /R:43200 /W:1 

------------------------------------------------------------------------------

	  *EXTRA File 		  10.4 m	X:\HMS-BACKUP-TEMP\hMailData\MYSQLDump_2018-09-29-235800.mysql
	    Older     		    3784	X:\HMS-DATA\Data\{6B5B1373-777D-4E79-8EAF-9F0731966BBE}.eml
	    Older     		    3409	X:\HMS-DATA\Data\{9C37C091-7D48-4A77-B5A0-A5EE780F33EC}.eml
	    Older     		    3000	X:\HMS-DATA\Data\mydomain.tld\a\03\{03E84872-31CD-4A54-BF4D-82D0718A9C80}.eml
	    Older     		     977	X:\HMS-DATA\Data\mydomain.tld\a\05\{050E71B0-15D8-4812-881D-8B02C25CBCA5}.eml
	    Older     		     615	X:\HMS-DATA\Data\mydomain.tld\a\05\{051B778C-8A53-4176-8CA4-4694B139FBC7}.eml
	    Older     		    1326	X:\HMS-DATA\Data\mydomain.tld\a\06\{06F08187-0AA9-475B-9613-E00AC6926C29}.eml
	    Older     		   9.3 m	X:\HMS-DATA\Data\mydomain.tld\a\0F\{0FD9B601-E9F7-4586-B591-AD488E05D43E}.eml
	    Older     		     853	X:\HMS-DATA\Data\mydomain.tld\a\10\{1082D5F5-E54A-46CB-8489-64417202D6B5}.eml
	    Older     		   22841	X:\HMS-DATA\Data\mydomain.tld\a\14\{14E6AEFB-80C5-4ABD-B730-39A8BC8E3837}.eml
	    Older     		    4379	X:\HMS-DATA\Data\mydomain.tld\a\17\{17D99471-34F0-424F-9824-2FDDAEC8BDC8}.eml
That's just a snippet of the top. I never saw "Older" before. I don't know what it means. Everything else looks fine - the backup finished, the backup file size is the expected size, etc. What does "Older" mean and will I see this often?

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-10-01 14:38

Robocopy does a timestamp check. I suspect overnight (being 1st October) your server has automatically changed time (- 1 hour) but the destination server hasn't. (Or the other way around).
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

User avatar
SorenR
Senior user
Senior user
Posts: 3169
Joined: 2006-08-21 15:38
Location: Denmark

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by SorenR » 2018-10-01 15:31

jimimaseye wrote:
2018-10-01 14:38
Robocopy does a timestamp check. I suspect overnight (being 1st October) your server has automatically changed time (- 1 hour) but the destination server hasn't. (Or the other way around).
DST ??

https://www.timeanddate.com/time/change/usa/new-york
SørenR.

The quantum rule of insecurity which states that the act of observing how vulnerable a host or service is changes the insecurity level of the service.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-01 16:06

Definitely not time change. Server is local (in my house) and time is correct.

However, I was poking around the backup-temp dir yesterday looking for a few specific messages. Maybe this is a result of the "modified" timestamp changing? I only opened the .eml files from a single account and did not modify them - only viewed.

~~~~~~~~~~

I just looked at a couple of them again (viewed properties only) and see there is an "accessed" timestamp. I guess that's the cause.

User avatar
SorenR
Senior user
Senior user
Posts: 3169
Joined: 2006-08-21 15:38
Location: Denmark

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by SorenR » 2018-10-01 17:23

"Older" means that source is Older than destination.

You can use the /FFT switch to Assume FAT File Times (2-second date/time granularity) if you are copying between different filesystems (NTFS/FAT/ext2/ext3/ext4 etc.).
SørenR.

The quantum rule of insecurity which states that the act of observing how vulnerable a host or service is changes the insecurity level of the service.

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-10-01 19:21

palinka wrote:
2018-10-01 16:06
Definitely not time change. Server is local (in my house) and time is correct.

However, I was poking around the backup-temp dir yesterday looking for a few specific messages. Maybe this is a result of the "modified" timestamp changing? I only opened the .eml files from a single account and did not modify them - only viewed.

~~~~~~~~~~

I just looked at a couple of them again (viewed properties only) and see there is an "accessed" timestamp. I guess that's the cause.
No. Viewing doesn't change 'modified' stamps. I would put money on it being a system time difference (especially if one system is Linux and the other is windows.)
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-01 19:29

All of this is taking place on the same machine. Backup dirs are local drives. The time zone did not change here or on the server (is set to auto time zone).

Could it have something to do with the clock and automatic time synchronization with time.windows.com?

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2018-10-01 19:57

Take a look at the timestamp for the files on the local and backup drive. I'm guessing they are all different by a single or multiple of an hour.

You can figure out the rest.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-01 21:49

I checked several at the top of the "Older" list randomly. Not exhaustive by any means, but I didn't see any differences in modified date/time.
2018-10-01 (1)_LI.jpg

I just realized what part of the confusion might be. I save the backups to the same drive. The zip files are then saved to an external location. I'm not backing up directly to external location.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-02 01:13

I read something online about the difference between robocopy /mir and /xo switches with /xo being more tolerant of modify time differences (2 seconds). That lead me to go back to the hms data and backuptemp directories to look more closely than the minutes only (no seconds shown) in windows explorer view frame. However, I made a very weird discovery. Merely hovering the mouse over the file changed the modified attribute to the current time. No shit! But this only happens, as far as my very limited testing goes, in those two folders. I don't understand why, but because of that - merely opening to view, or hovering the mouse over the .eml file - the modify dates changed and robocopy picks them up. Weird.

I still don't understand why all files would have the modify attribute after messing with just a few. The only thing I can think of is the modify date went up to the top of the folder structure and robocopy copied all files within due to that.

Lesson - don't mess with the data dir. :mrgreen:

User avatar
mattg
Moderator
Moderator
Posts: 19979
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by mattg » 2018-10-02 01:41

In Windows explorer, do you routinely show a preview of the document?
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-02 02:10

mattg wrote:
2018-10-02 01:41
In Windows explorer, do you routinely show a preview of the document?
No. Not preview. Just view pane. Maybe I have the nomenclature wrong. The same as is shown in the screen shot above.

And yeah, it's bizarre. I can't replicate anywhere except within the HMS data directory and the backup script backup-temp folder.

I just had a thought - .eml files are (on my server) associated with sylpheed. Maybe it's sylpheed causing this behavior. I'll remove it and try again.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-02 02:22

Got rid of sylpheed and no change. Modified date still changes to current after hovering the mouse. File association is now win10 mail app.

User avatar
mattg
Moderator
Moderator
Posts: 19979
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by mattg » 2018-10-02 03:34

If you wanted to exclude OLDER files you just add
/XO

to your robocopy command lines

I'm not sure if you should do that or not though

ALSO, is there an antivirus installed on this machine where the copied data is located
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

User avatar
mattg
Moderator
Moderator
Posts: 19979
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by mattg » 2018-10-02 03:39

And just found this

https://conetrix.com/blog/robocopy-inco ... le-systems

basically, just add a /FFT switch and the time difference allows a 2 second difference and still accepts them as the same file
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2018-10-02 11:54

Today's log is *almost* back to normal. There are a few "older" entries but they appear to be only the files I was messing with yesterday, not the entire data store like the day before.

And yes, there is antivirus installed.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-01-29 11:51

Yesterday i helped my son delete 5k bulk commercial messages from his inbox and got his total number of messages (in all folders) down to about 200 (from over 5k!). I was expecting to wake up this morning with a backup log that's yuuuuuge from all the messages that were deleted but they didn't show up as extras in robocopy.

I looked at the folder properties for the mailbox in the data dir (not backup temp data dir) and it showed 4700+ files. Not quite as many as i deleted. Isn't hmailserver supposed to delete the messages when they're deleted from the mailbox?

After searching and deleting these messages from the inbox, i emptied the trash folder and assumed they were gone forever. This was via imap.

User avatar
SorenR
Senior user
Senior user
Posts: 3169
Joined: 2006-08-21 15:38
Location: Denmark

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by SorenR » 2019-01-29 12:46

My ancient Outlook 2003 show deleted mails with a line thru... Waiting to be expunged. Wife's iPad dont show them at all.

IIRC there were a topic on expunging and flags not so long ago...
SørenR.

The quantum rule of insecurity which states that the act of observing how vulnerable a host or service is changes the insecurity level of the service.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-01-29 13:38

SorenR wrote:
2019-01-29 12:46
My ancient Outlook 2003 show deleted mails with a line thru... Waiting to be expunged. Wife's iPad dont show them at all.

IIRC there were a topic on expunging and flags not so long ago...
I'll look for it.

By the way, the IMAP client was windows mail that came with vista (ancient laptop I set up for the boy's schoolwork).

Edit - I just logged into his account in horde webmail, which does show strikethrough and you were correct. Expunging in process. Crappy mail client, but then what should I have expected from vista mail? :mrgreen:

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-17 19:25

So every once in a while a ghost in the machine causes hmailserver to not shut down properly, which causes the script to fail completely. Obviously I can't be notified by email if my email server is down. Something I wanted to do for a while is set up a SMS gateway, which I did last night using a spare SIM I have with my mobile plan and gammu/kalkun as the gateway. I can send SMS messages by launching a vbscript. Where would I put this in the backup script to make sure it runs if hmailserver either fails to shut down or fails to restart? Would something like this work?

Code: Select all

:1st
:maildata
echo %time% Stopping Hmailserver service...>> %BackLog%&net stop hmailserver >> %BackLog%
set FailedHmailservice=Ok
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedHmailservice=Failed to stop. Backup of emails not performed!&set bold=b&set fontcolor=%colorfill%
if errorlevel 1 cscript C:\scripts\HMSBackupCleardown\sms-server-down.vbs //nologo //T:600   >> %BackLog%
echo %FailedHmailservice%! >> %BackLog%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Hmailserver service shutdown:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedHmailservice%^</td^>^</tr^> >>%outf%

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2019-02-17 23:09

palinka wrote:
2019-02-17 19:25
So every once in a while a ghost in the machine causes hmailserver to not shut down properly, which causes the script to fail completely. Obviously I can't be notified by email if my email server is down. Something I wanted to do for a while is set up a SMS gateway, which I did last night using a spare SIM I have with my mobile plan and gammu/kalkun as the gateway. I can send SMS messages by launching a vbscript. Where would I put this in the backup script to make sure it runs if hmailserver either fails to shut down or fails to restart? Would something like this work?

Code: Select all

:1st
:maildata
echo %time% Stopping Hmailserver service...>> %BackLog%&net stop hmailserver >> %BackLog%
set FailedHmailservice=Ok
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedHmailservice=Failed to stop. Backup of emails not performed!&set bold=b&set fontcolor=%colorfill%
if errorlevel 1 cscript C:\scripts\HMSBackupCleardown\sms-server-down.vbs //nologo //T:600   >> %BackLog%
echo %FailedHmailservice%! >> %BackLog%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Hmailserver service shutdown:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedHmailservice%^</td^>^</tr^> >>%outf%
Err... if the email service has failed to stop then you can still email. :roll: If the email service has failed to RESTART then yes you would need the SMS system.

In any case, (if you still wanted to SMS on a failure to stop) then yes, your proposal above is the correct place. Also similar for the HMS Service restart section.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

User avatar
mattg
Moderator
Moderator
Posts: 19979
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by mattg » 2019-02-18 01:15

palinka wrote:
2019-02-17 19:25
... is set up a SMS gateway, which I did last night using a spare SIM I have with my mobile plan and gammu/kalkun as the gateway.
What hardware did you use to achieve this??
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-18 01:22

mattg wrote:
2019-02-18 01:15
palinka wrote:
2019-02-17 19:25
... is set up a SMS gateway, which I did last night using a spare SIM I have with my mobile plan and gammu/kalkun as the gateway.
What hardware did you use to achieve this??
I bought the cheapest usb modem i could find on Amazon. $10 huawei e352. Getting gammu to work was kind of a pain since the project is kind of old and windows was a side thought. You'll have many more options on linux. Or you can jump through hoops like me. :mrgreen:

You can use an old mobile phone too. I considered that too (free) but i tried it with an android app a long time ago and it didn't work well and caused the phone to crash after a day or 2. I think it's better to have computer hardware.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-18 01:32

jimimaseye wrote:
2019-02-17 23:09

Err... if the email service has failed to stop then you can still email. :roll: If the email service has failed to RESTART then yes you would need the SMS system.

In any case, (if you still wanted to SMS on a failure to stop) then yes, your proposal above is the correct place. Also similar for the HMS Service restart section.
Sorry, i didn't really explain the situation. Hmailserver gets hung in those cases when it doesn't shut down properly. Then the script fails too, apparently. This is the entirety of the log from last night:

Code: Select all

Backup Start: Sat 02/16/2019 23:58:02.39 


HMS Server Start Time: 2019-02-16 22:47:26
HMS Daily Spam Reject count: 1
HMS Daily Viruses Removed count: 2



And from the hmailserver log (omitting the log spam) :

Code: Select all

"DEBUG"	5416	"2019-02-16 23:58:13.296"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:13.505"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:13.568"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"Given up waiting for threads to join in queue Server queue."
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"WorkQueueManager::RemoveQueue - Stopped Server queue"
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"WorkQueueManager::RemoveQueue - Erased Server queue"
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"Destructing work queue Server queue"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"Given up waiting for threads to join in queue IOCPQueue."
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"WorkQueueManager::RemoveQueue - Stopped IOCPQueue"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"WorkQueueManager::RemoveQueue - Erased IOCPQueue"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"IOService::Stop() - Complete"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"Destructing work queue IOCPQueue"
"DEBUG"	5612	"2019-02-16 23:58:22.659"	"Event completed"
"DEBUG"	5612	"2019-02-16 23:58:22.659"	"TCP connection started for session 63"
"SMTPD"	5612	63	"2019-02-16 23:58:22.659"	"208.66.204.138"	"SENT: 220 mydomain"
"DEBUG"	5536	"2019-02-16 23:59:11.247"	"No messages to index."

It looks like it shut down properly, but it got hung up from there. The rest of the log until i rebooted is just connection entries. I could not log in to imap. That's why the sms would be great. At least I'll know as soon as i wake up.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-18 14:54

I'm just thinking about why the backup script didn't complete. If you look at the log for the run that failed, you'll see the last entry comes from serverstatusreport.vbs.

At a bare minimum, the next line should have been:

%time% Stopping Hmailserver service..

I know from the hmailserver log that the net stop command was initiated because hmailserver actually did attempt to shut down.

Echo message comes before net stop.

Code: Select all

echo %time% Stopping Hmailserver service...>> %BackLog%&net stop hmailserver >> %BackLog%
I'm not sure what went wrong, but if the backup script hangs, then it won't perform my sms notification either. Any ideas?

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2019-02-18 15:25

palinka wrote:
2019-02-18 14:54
I'm just thinking about why the backup script didn't complete. If you look at the log for the run that failed, you'll see the last entry comes from serverstatusreport.vbs.
Can you show it?
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

User avatar
SorenR
Senior user
Senior user
Posts: 3169
Joined: 2006-08-21 15:38
Location: Denmark

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by SorenR » 2019-02-18 15:30

I run this monitor on my server via Scheduler every 10 minutes.

90% of the code is actually the logfile writer :roll:
The section "CODE" is where the action is.

I do a simple check here but this could easily be expanded to do the SMS thingy via API to a GSM device, a SMSC/MMSC connected to a GSM backboe or via The Internet to a HLR. If you should be so lucky to have your own SGSN, that would be even easier.

Code: Select all

If oApp.ServerState = 1 Then
   If (FSO.FolderExists(oApp.Settings.Backup.Destination & "\DataBackup")) Then
      EventLogX.Write("CheckState: Server is currently doing backup...")
   Else
      EventLogX.Write("CheckState: Server was stopped for no reason, starting...")
      Call oApp.Start
   End If
End If

Code: Select all

hStateStopped = 1, Server is stopped.
hStateStarting = 2, Server is starting.
hStateRunning = 3, Server is running.
hStateStopping = 4, Server is stopping.
Name: CheckState.vbs

Code: Select all

Option Explicit

'******************************************************************************************************************************
'********** Settings                                                                                                 **********
'******************************************************************************************************************************

'
'   COM authentication
'
Private Const ADMIN = "Administrator"
Private Const PASSWORD = "MUCHO SECRETO"

'******************************************************************************************************************************
'********** Classes                                                                                                  **********
'******************************************************************************************************************************

Class LogWriter
   Private m_oApp, m_LogID, m_LogFile, m_LogType, m_LogDir
   Private i, t, temp, strDay, strMonth, strTime, strLogFile, strLogDate
   
   Private Sub Class_Initialize()
      Set m_oApp = CreateObject("hMailServer.Application")
      Call m_oApp.Authenticate(ADMIN, PASSWORD)
      m_LogFile = "LogWriter"
      m_LogType = "M"
      m_LogDir = m_oApp.Settings.Directories.LogDirectory
      m_LogID = CStr(m_oApp.Status.ProcessedMessages)
   End Sub
   
   Private Sub Class_Terminate()
      '
      '   Termination code goes here
      '
   End Sub
   
   Public Property Let LogFile(strFile)
   m_LogFile = Trim(strFile)
   End Property
   
   Public Property Let LogDir(strDir)
   If Right(strDir, 1) = "\" Then
      m_LogDir = Trim(Left(strDir, Len(strDir) - 1))
   Else
      m_LogDir = Trim(strDir)
   End If
   End Property
   
   Public Property Let LogType(strType)
   m_LogType = Trim(strType)
   End Property
   
   Public Function Wait(sec)
      With CreateObject("WScript.Shell")
         .Run "timeout /T " & Int(sec), 0, True
'        .Run "sleep -m " & Int(sec * 1000), 0, True
'        .Run "powershell Start-Sleep -Milliseconds " & Int(sec * 1000), 0, True
      End With
   End Function
   
   Public Function OpenFile(strPath)
      Const Append = 8
      Const Unicode = -1
      With CreateObject("Scripting.FileSystemObject")
         Dim oFile
         For i = 0 To 30
            On Error Resume Next
            Set oFile = .OpenTextFile(strPath, Append, True, Unicode)
            If Not (Err.Number = 70) Then
               Set OpenFile = oFile
               On Error Goto 0
               Exit For
            End If
            On Error Goto 0
            Wait(1)
         Next
      End With
      If (Err.Number = 70) Then
         EventLog.Write( "ERROR: VBScript Class LogWriter" )
         EventLog.Write( "File " & strPath & " is locked and timeout was exceeded." )
         Err.Clear
      ElseIf (Err.Number <> 0) Then
         EventLog.Write( "ERROR: VBScript Class LogWriter : Function OpenFile" )
         EventLog.Write( "Error       : " & Err.Number )
         EventLog.Write( "Error (hex) : 0x" & Hex(Err.Number) )
         EventLog.Write( "Source      : " & Err.Source )
         EventLog.Write( "Description : " & Err.Description )
         Err.Clear
      End If
   End Function
   
   Public Function Write(strText)
      t = Timer
      temp = Int(t)
      strMonth = DatePart("yyyy",Date) & "-" & Right("0" & DatePart("m",Date), 2)
      strDay = strMonth & "-" & Right("0" & DatePart("d",Date), 2)
      strTime = Right("0"  & Hour(Now),   2) & ":" &_
      Right("0"  & Minute(Now), 2) & ":" &_
      Right("0"  & Second(Now), 2) & "." &_
      Right("00" & (Int((t-temp) * 1000)), 3)
      strLogDate = strDay & " " & strTime
      If (m_LogType = "M") Then
         strLogFile = m_LogDir & "\" & m_LogFile & "_" & strMonth & ".log"
      Else
         strLogFile = m_LogDir & "\" & m_LogFile & "_" & strDay & ".log"
      End If
      With OpenFile(strLogFile)
         .WriteLine(m_LogID & vbTab & Chr(34) & strLogDate & Chr(34) & vbTab & Chr(34) & strText & Chr(34))
         .Close
      End With
      Write = Err.Number
   End Function
   
End Class

'******************************************************************************************************************************
'********** CODE                                                                                                     **********
'******************************************************************************************************************************

Dim oApp : Set oApp = CreateObject("hMailServer.Application")
Call oApp.Authenticate(ADMIN, PASSWORD)
Dim EventLog : Set EventLog = CreateObject("hMailServer.EventLog")
Dim FSO : Set FSO = CreateObject("Scripting.FileSystemObject")
Dim EventLogX : Set EventLogX = New LogWriter
'
'   Name of the logfile.
'   Default is monthly logs, for daily logs add: EventLogX.LogType = "D"
'
EventLogX.LogFile = "checkstate"
If oApp.ServerState = 1 Then
   If (FSO.FolderExists(oApp.Settings.Backup.Destination & "\DataBackup")) Then
      EventLogX.Write("CheckState: Server is currently doing backup...")
   Else
      EventLogX.Write("CheckState: Server was stopped for no reason, starting...")
      Call oApp.Start
   End If
End If

'******************************************************************************************************************************
'********** END                                                                                                      **********
'******************************************************************************************************************************
SørenR.

The quantum rule of insecurity which states that the act of observing how vulnerable a host or service is changes the insecurity level of the service.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-18 17:34

jimimaseye wrote:
2019-02-18 15:25
palinka wrote:
2019-02-18 14:54
I'm just thinking about why the backup script didn't complete. If you look at the log for the run that failed, you'll see the last entry comes from serverstatusreport.vbs.
Can you show it?
serverstatusreport.vbs:

Code: Select all

Set oApp = CreateObject("hMailServer.Application")
Call oApp.Authenticate("Administrator", "SECRET PASSWORD" )
   
wscript.echo vbCrLf
wscript.echo "HMS Server Start Time: " & oApp.status.StartTime
wscript.echo "HMS Daily Spam Reject count: " & oApp.status.RemovedSpamMessages
wscript.echo "HMS Daily Viruses Removed count: " & oApp.status.RemovedViruses & vbCrLf
oApp.stop
Backup Log from that FUBAR night in its entirety:

Code: Select all

Backup Start: Sat 02/16/2019 23:58:02.39 


HMS Server Start Time: 2019-02-16 22:47:26
HMS Daily Spam Reject count: 1
HMS Daily Viruses Removed count: 2

Hmailserver log. Its set to run at 11:58 pm nightly. At the top, I included the last entry before the script ran.

Code: Select all

"DEBUG"	5612	"2019-02-16 23:58:00.960"	"Creating session 68"
"TCPIP"	5612	"2019-02-16 23:58:00.960"	"TCP - 208.66.204.138 connected to 192.168.1.2:25."
"DEBUG"	5612	"2019-02-16 23:58:00.960"	"Executing event OnClientConnect"
"APPLICATION"	7380	"2019-02-16 23:58:02.554"	"Stopping servers..."
"DEBUG"	7380	"2019-02-16 23:58:02.554"	"Application::StopServers() - Removing server work queue"
"DEBUG"	7380	"2019-02-16 23:58:02.554"	"WorkQueueManager::RemoveQueue - Server queue"
"DEBUG"	7380	"2019-02-16 23:58:02.554"	"Stopping working queue Server queue."
"DEBUG"	7380	"2019-02-16 23:58:02.554"	"Interupt and join threads in working queue Server queue"
"DEBUG"	5412	"2019-02-16 23:58:02.554"	"Worker exited in work queue Server queue"
"DEBUG"	5416	"2019-02-16 23:58:02.554"	"IOService::Stop()"
"DEBUG"	5424	"2019-02-16 23:58:02.569"	"Worker exited in work queue Server queue"
"DEBUG"	5416	"2019-02-16 23:58:02.569"	"IOService::DoWork() - removing Queue IOCP Queue"
"DEBUG"	5420	"2019-02-16 23:58:02.569"	"Worker exited in work queue Server queue"
"DEBUG"	5604	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5596	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5620	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5636	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5624	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5632	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5616	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	5416	"2019-02-16 23:58:02.569"	"WorkQueueManager::RemoveQueue - IOCPQueue"
"DEBUG"	7380	"2019-02-16 23:58:02.569"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5604	"2019-02-16 23:58:02.569"	"Ending session 25"
"DEBUG"	5596	"2019-02-16 23:58:02.569"	"Ending session 64"
"DEBUG"	5620	"2019-02-16 23:58:02.569"	"Ending session 5"
"DEBUG"	5636	"2019-02-16 23:58:02.569"	"Ending session 35"
"DEBUG"	5624	"2019-02-16 23:58:02.569"	"Ending session 67"
"DEBUG"	5632	"2019-02-16 23:58:02.569"	"Ending session 2"
"DEBUG"	5616	"2019-02-16 23:58:02.569"	"Ending session 68"
"DEBUG"	5416	"2019-02-16 23:58:02.569"	"Stopping working queue IOCPQueue."
"DEBUG"	5604	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5632	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5596	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5620	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5636	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5624	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5616	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5416	"2019-02-16 23:58:02.585"	"Interupt and join threads in working queue IOCPQueue"
"DEBUG"	5580	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5584	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5588	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5592	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5600	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5628	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5608	"2019-02-16 23:58:02.585"	"Worker exited in work queue IOCPQueue"
"DEBUG"	5416	"2019-02-16 23:58:02.616"	"Still 2 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:02.850"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:02.897"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:03.132"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:03.179"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:03.413"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:03.460"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:03.694"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:03.741"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:03.975"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:04.022"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:04.257"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:04.304"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:04.538"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:04.585"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:04.819"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:04.866"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:05.101"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:05.147"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:05.382"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:05.429"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:05.663"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:05.710"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:05.944"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:05.991"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:06.226"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:06.272"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:06.507"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:06.554"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:06.788"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:06.835"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:07.069"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:07.116"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:07.351"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:07.397"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:07.632"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:07.679"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:07.913"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:07.960"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:08.194"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:08.241"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:08.476"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:08.522"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:08.757"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:08.804"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	5536	"2019-02-16 23:58:08.882"	"No messages to index."
"DEBUG"	7380	"2019-02-16 23:58:09.038"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:09.085"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:09.319"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:09.366"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:09.601"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:09.647"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:09.882"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:09.929"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:10.163"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:10.210"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:10.444"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:10.491"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:10.716"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:10.763"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:10.997"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:11.044"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:11.264"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:11.327"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:11.546"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:11.608"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:11.827"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:11.889"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:12.108"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:12.171"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:12.389"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:12.452"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:12.671"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:12.733"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:12.952"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:13.014"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:13.233"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:13.296"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:13.505"	"Still 1 remaining threads in queue Server queue. First task: IOService"
"DEBUG"	5416	"2019-02-16 23:58:13.568"	"Still 1 remaining threads in queue IOCPQueue. First task: IOCPQueueWorkerTask"
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"Given up waiting for threads to join in queue Server queue."
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"WorkQueueManager::RemoveQueue - Stopped Server queue"
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"WorkQueueManager::RemoveQueue - Erased Server queue"
"DEBUG"	7380	"2019-02-16 23:58:13.771"	"Destructing work queue Server queue"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"Given up waiting for threads to join in queue IOCPQueue."
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"WorkQueueManager::RemoveQueue - Stopped IOCPQueue"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"WorkQueueManager::RemoveQueue - Erased IOCPQueue"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"IOService::Stop() - Complete"
"DEBUG"	5416	"2019-02-16 23:58:13.833"	"Destructing work queue IOCPQueue"
"DEBUG"	5612	"2019-02-16 23:58:22.659"	"Event completed"
"DEBUG"	5612	"2019-02-16 23:58:22.659"	"TCP connection started for session 63"
"SMTPD"	5612	63	"2019-02-16 23:58:22.659"	"208.66.204.138"	"SENT: 220 mydomain"
"DEBUG"	5536	"2019-02-16 23:59:11.247"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:00:13.615"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:01:15.970"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:02:18.338"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:03:20.711"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:04:23.062"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:05:25.433"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:06:27.803"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:07:30.168"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:08:32.522"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:09:34.895"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:10:37.246"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:11:39.619"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:12:41.983"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:13:44.351"	"No messages to index."
"DEBUG"	5536	"2019-02-17 00:14:46.704"	"No messages to index."
The debug "No messages to index." went on until I rebooted.

Here is my script except for the user variables at the top. My changes are cycling the SA log, downloading KAM and (since yesterday only) the sms notice.

Code: Select all

rem  ****  FILL OUT VARIABLES ABOVE  *******************************
rem   #### CONFIG END ####

Set SCRIPTdir=%~dp0

for /F "usebackq tokens=1,2 delims==" %%i in (`wmic os get LocalDateTime /VALUE 2^>NUL`) do if '.%%i.'=='.LocalDateTime.' set ldt=%%j
set inDate=%ldt:~0,4%-%ldt:~4,2%-%ldt:~6,2%-%ldt:~8,6%
set BackLog="%BACKUPdir%\Backup_%inDate%.log"
set emailer_log="%SCRIPTdir%\emailer.log"
set Failed=false
set FailedScript=Not performed
set FailedZip=Not performed
set FailedSAUpdate=Not performed
set FailedSAService=Not performed
set FailedDNSService=Not performed
set FailedHmailservice=Not performed
set outf="%SCRIPTdir%\body.html"

echo ^<table border='0'^> > %outf%

set colorfill=font color="red"
set fontBlack=!--
set noBold=!--

echo Backup Start: %date% %time% > %BackLog%

cscript C:\scripts\HMSBackupCleardown\serverstatusreport.vbs //nologo //T:600   >> %BackLog%

REM :: Perform backup to temporary directory

set section=1st

:1st
:maildata
echo %time% Stopping Hmailserver service...>> %BackLog%&net stop hmailserver >> %BackLog%
set FailedHmailservice=Ok
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedHmailservice=Failed to stop. Backup of emails not performed!&set bold=b&set fontcolor=%colorfill%
if errorlevel 1 cscript C:\scripts\HMSBackupCleardown\sms-serverdown.vbs //nologo //T:600   >> %BackLog%
echo %FailedHmailservice%! >> %BackLog%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Hmailserver service shutdown:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedHmailservice%^</td^>^</tr^> >>%outf%

:2nd
if not "%SA_In_Use%" == "yes" goto 3rd
echo %time% Stopping Spamassassin service...>> %BackLog%&net stop spamassassin >> %BackLog%
set FailedSAService=Ok
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedSAService=Failed to stop&set bold=b&set fontcolor=%colorfill%
echo %FailedSAService%! >> %BackLog%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Spamassassin service shutdown:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedSAService%^</td^>^</tr^> >>%outf%

@rem Update Spamassassin before restarting service
if "%FailedSAService%" == "Failed to stop" goto 3rd
echo %time% Performing Spamassassin Update check...>> %BackLog%
set FailedSAUpdate=Ok
cd /D %SPAMASSASSINdir%
sa-update.exe -v --nogpg --channelfile UpdateChannels.txt >> %BackLog%
wget -q http://www.pccc.com/downloads/SpamAssassin/contrib/KAM.cf -O "C:\Program Files\JAM Software\SpamAssassin for Windows\etc\spamassassin\KAM.cf" >> %BackLog%
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedSAUpdate=Failed&set bold=b&set fontcolor=%colorfill%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Spam Assassin Def Update:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedSAUpdate%^</td^>^</tr^> >>%outf%

set hr=%time:~0,2%
if "%hr:~0,1%" equ " " set hr=0%hr:~1,1%
ren "C:\Program Files (x86)\hMailServer\Logs\spamd.log" spamd-%date:~-4,4%-%date:~-10,2%-%date:~-7,2%.log"

:3rd
set section=3rd
if "%FailedHmailservice:~0,14%" == "Failed to stop" goto 5th
robocopy "%MAILDATAdir%" "%BACKUPTEMPdir%"\hMailData /mir /ndl /r:43200 /np /w:1 >> %BackLog%
goto ROBOerrorcheck

:4th
if "%DBtype%" == "mysql" (
   erase /Q "%BACKUPTEMPdir%"\hMailData\*.mysql >> %BackLog%
   "%MYSQLBINdir%"\mysqldump -u"%MYSQLDBuser%" -p"%MYSQLDBpass%" -q -A -l --add-drop-table -PMYSQLDBport >"%BACKUPTEMPdir%\hMailData\MYSQLDump_%inDate%.mysql"
) ELSE (
   robocopy "%InternalDATABASEdir%" "%BACKUPTEMPdir%"\Database /mir /ndl /r:43200 /np /w:1 >> %BackLog%
   goto ROBOerrorcheck
)

:5th
@rem Restart Spamassassin and Hmailserver services
if not "%FailedSAService%" == "Ok" goto 6th
echo %time% Starting Spamassassin service...>> %BackLog%&net start spamassassin >> %BackLog%
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedSAService=Failed to restart&set bold=b&set fontcolor=%colorfill%
echo %FailedSAService%! >> %BackLog%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Spam Assassin Service startup: ^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedSAService%^</td^>^</tr^> >>%outf%

:6th
if not "%FailedHmailservice%" == "Ok" set section=7th & goto 7th
echo %time% Starting Hmailserver service... >> %BackLog%&net start hmailserver >> %BackLog%
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedHmailservice=Failed to restart&set bold=b&set fontcolor=%colorfill%
if errorlevel 1 cscript C:\scripts\HMSBackupCleardown\sms-serverdown.vbs //nologo //T:600   >> %BackLog%
echo %FailedHmailservice%! Errorlevel=%errorlevel% >> %BackLog%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Hmailserver service startup:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedHmailservice%^</td^>^</tr^> >>%outf%

REM --- Use the following sections 7th to 9th as example of adding other Data directories in the backup (remove the REM's)  ---
:7th
:Sagedata
rem robocopy "D:\SageAccountData" "%BACKUPTEMPdir%"\SageAccountData /mir /ndl /r:43200 /np /w:1 >> %BackLog%
rem goto ROBOerrorcheck

:8th
:Miscdata
rem robocopy "D:\Miscdata" "%BACKUPTEMPdir%"\Miscdata /mir /ndl /r:43200 /np /w:1 >> %BackLog%
rem goto ROBOerrorcheck

:9th
rem robocopy "D:\anotherdir" "%BACKUPTEMPdir%"\anotherdir /mir /ndl /r:43200 /np /w:1 >> %BackLog%
rem goto ROBOerrorcheck

REM --- End of Example sections  ---

:10th
REM::  Clear down existing backup Zips over DAYSZIPTOKEEP
echo. & echo Clearing old archives
forfiles.exe /s /p "%BACKUPdir%" /m *.* /d -%DAYSZIPTOKEEP% /c "cmd /c echo Deleting over %DAYSZIPTOKEEP% days....@path & del /q @path" >> %BackLog%

REM :: Zip temporary directory and email log file
cd /D "%HMAILSERVERprogdir%"\Bin >> %BackLog%
echo %date% %time% 7Zip Creating archive %BACKUPdir%\Serverdata_%inDate%.zip >> %BackLog%
set FailedZip=Ok
7za a -tzip "%BACKUPdir%\Serverdata_%inDate%" "%BACKUPTEMPdir%\*"
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedZip=Failed&set bold=b&set fontcolor=%colorfill%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Zip:^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedZip%^</td^>^</tr^> >>%outf%

REM :: Empty the Trash folder
echo. >> %BackLog%
set FailedScript=Ok
:runcleardown
echo Email clear up started at %time% ************************************ >> %BackLog%
cscript "%SCRIPTdir%"\EmailClearup.vbs //nologo //T:600   >> %BackLog%
echo Email clear up finished at %time% (errorlevel: %errorlevel%) **********************>> %BackLog%
if "%FailedScript%" == "RERUN-Ok" goto skiprun
if errorlevel 1 set FailedScript=RERUN-Ok& echo RERUN being called......***************>> %BackLog% & goto runcleardown
:skiprun
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedScript=Failed&set bold=b&set fontcolor=%colorfill%
echo ^<tr^>^<td^>^<%fontcolor%^>^<%bold%^>Email Cleardown Script: ^</td^>^<td^>^<%fontcolor%^>^<%bold%^>%FailedScript%^</td^>^</tr^> >>%outf%

:test
set result=%date% %time% Backup procedure FAILED!!! Zip: %FailedZip%, Script: %FailedScript%, SA Update: %FailedSAUpdate%, SA Service: %FailedSAService%, Hmailserver service: %FailedHmailservice%.
set resulttext="!!! Backup completed WITH ERRORS.  CHECK LOG FILE FOR DETAILS!!!"
if not %Failed%==false goto Testend
:success
set result=%date% %time% Backup 7Zip Archive created - no errors encountered.
set resulttext="Backup completed. See attachment log file."
goto Testend

:ROBOerrorcheck
if errorlevel 16 echo ***FATAL ERROR*** >> %BackLog% & goto end
if errorlevel 15 echo OKCOPY + FAIL + MISMATCHES + XTRA >> %BackLog% & goto end
if errorlevel 14 echo FAIL + MISMATCHES + XTRA >> %BackLog% & goto end
if errorlevel 13 echo OKCOPY + FAIL + MISMATCHES >> %BackLog% & goto end
if errorlevel 12 echo FAIL + MISMATCHES>> %BackLog% & goto end
if errorlevel 11 echo OKCOPY + FAIL + XTRA >> %BackLog% & goto end
if errorlevel 10 echo FAIL + XTRA >> %BackLog% & goto end
if errorlevel 9 echo OKCOPY + FAIL >> %BackLog% & goto end
if errorlevel 8 echo FAIL >> %BackLog% & goto end
if errorlevel 7 echo OKCOPY + MISMATCHES + XTRA >> %BackLog% & goto end
if errorlevel 6 echo MISMATCHES + XTRA >> %BackLog% & goto end
if errorlevel 5 echo OKCOPY + MISMATCHES >> %BackLog% & goto end
if errorlevel 4 echo MISMATCHES >> %BackLog% & goto end
if errorlevel 3 echo OKCOPY + XTRA >> %BackLog% & goto end
if errorlevel 2 echo XTRA >> %BackLog% & goto end
if errorlevel 1 echo OKCOPY  >> %BackLog% & goto end
if errorlevel 0 echo No Change >> %BackLog% & goto end
:end
if errorlevel 8 set Failed=true
if %section%==9th set section=10th
if %section%==8th set section=9th
if %section%==7th set section=8th
if %section%==6th set section=7th
if %section%==5th set section=6th
if %section%==4th set section=5th
if %section%==3rd set section=4th
if %section%==2nd set section=3rd
if %section%==1st set section=2nd
goto %section%

:Testend
if not %FailedZip%==Failed forfiles /p "%BACKUPdir%" /m Serverdata_%inDate%.zip /d +0 /c "cmd /c echo Created: @path @fsize" >> %BackLog%
echo ^<tr^>^<td^>^<br^>^</td^>^</tr^>^</table^>See attached log file below for details. >>%outf%
echo %result% >> %BackLog%

echo %time% %inDate% backup log.  Emailing.... >> %emailer_log%
:GoEmail
net start | find "hMailServer" > nul
if not %errorlevel%==0 echo Hmailservice not running - email not possible >> %emailer_log%&goto eof

if "%FailedHmailservice%" == "Failed to restart" echo Hmailservice not running - email not possible >> %emailer_log%&goto eof
"%BLATdir%" %outf% -mailfrom %emailFrom% -to %emailRecipient% -subject %resulttext% -server localhost -u %authUser% -pw %authPass% -port 587 -attach %BackLog% -log %emailer_log%
:eof
echo ********************************** >> %emailer_log%
del %outf%
:Finish

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-18 17:53

SorenR wrote:
2019-02-18 15:30
I run this monitor on my server via Scheduler every 10 minutes.

90% of the code is actually the logfile writer :roll:
The section "CODE" is where the action is.

I do a simple check here but this could easily be expanded to do the SMS thingy via API to a GSM device, a SMSC/MMSC connected to a GSM backboe or via The Internet to a HLR. If you should be so lucky to have your own SGSN, that would be even easier.

Code: Select all

If oApp.ServerState = 1 Then
   If (FSO.FolderExists(oApp.Settings.Backup.Destination & "\DataBackup")) Then
      EventLogX.Write("CheckState: Server is currently doing backup...")
   Else
      EventLogX.Write("CheckState: Server was stopped for no reason, starting...")
      Call oApp.Start
   End If
End If

Code: Select all

hStateStopped = 1, Server is stopped.
hStateStarting = 2, Server is starting.
hStateRunning = 3, Server is running.
hStateStopping = 4, Server is stopping.
Name: CheckState.vbs

Code: Select all

Option Explicit

'******************************************************************************************************************************
'********** Settings                                                                                                 **********
'******************************************************************************************************************************

'
'   COM authentication
'
Private Const ADMIN = "Administrator"
Private Const PASSWORD = "MUCHO SECRETO"

'******************************************************************************************************************************
'********** Classes                                                                                                  **********
'******************************************************************************************************************************

Class LogWriter
   Private m_oApp, m_LogID, m_LogFile, m_LogType, m_LogDir
   Private i, t, temp, strDay, strMonth, strTime, strLogFile, strLogDate
   
   Private Sub Class_Initialize()
      Set m_oApp = CreateObject("hMailServer.Application")
      Call m_oApp.Authenticate(ADMIN, PASSWORD)
      m_LogFile = "LogWriter"
      m_LogType = "M"
      m_LogDir = m_oApp.Settings.Directories.LogDirectory
      m_LogID = CStr(m_oApp.Status.ProcessedMessages)
   End Sub
   
   Private Sub Class_Terminate()
      '
      '   Termination code goes here
      '
   End Sub
   
   Public Property Let LogFile(strFile)
   m_LogFile = Trim(strFile)
   End Property
   
   Public Property Let LogDir(strDir)
   If Right(strDir, 1) = "\" Then
      m_LogDir = Trim(Left(strDir, Len(strDir) - 1))
   Else
      m_LogDir = Trim(strDir)
   End If
   End Property
   
   Public Property Let LogType(strType)
   m_LogType = Trim(strType)
   End Property
   
   Public Function Wait(sec)
      With CreateObject("WScript.Shell")
         .Run "timeout /T " & Int(sec), 0, True
'        .Run "sleep -m " & Int(sec * 1000), 0, True
'        .Run "powershell Start-Sleep -Milliseconds " & Int(sec * 1000), 0, True
      End With
   End Function
   
   Public Function OpenFile(strPath)
      Const Append = 8
      Const Unicode = -1
      With CreateObject("Scripting.FileSystemObject")
         Dim oFile
         For i = 0 To 30
            On Error Resume Next
            Set oFile = .OpenTextFile(strPath, Append, True, Unicode)
            If Not (Err.Number = 70) Then
               Set OpenFile = oFile
               On Error Goto 0
               Exit For
            End If
            On Error Goto 0
            Wait(1)
         Next
      End With
      If (Err.Number = 70) Then
         EventLog.Write( "ERROR: VBScript Class LogWriter" )
         EventLog.Write( "File " & strPath & " is locked and timeout was exceeded." )
         Err.Clear
      ElseIf (Err.Number <> 0) Then
         EventLog.Write( "ERROR: VBScript Class LogWriter : Function OpenFile" )
         EventLog.Write( "Error       : " & Err.Number )
         EventLog.Write( "Error (hex) : 0x" & Hex(Err.Number) )
         EventLog.Write( "Source      : " & Err.Source )
         EventLog.Write( "Description : " & Err.Description )
         Err.Clear
      End If
   End Function
   
   Public Function Write(strText)
      t = Timer
      temp = Int(t)
      strMonth = DatePart("yyyy",Date) & "-" & Right("0" & DatePart("m",Date), 2)
      strDay = strMonth & "-" & Right("0" & DatePart("d",Date), 2)
      strTime = Right("0"  & Hour(Now),   2) & ":" &_
      Right("0"  & Minute(Now), 2) & ":" &_
      Right("0"  & Second(Now), 2) & "." &_
      Right("00" & (Int((t-temp) * 1000)), 3)
      strLogDate = strDay & " " & strTime
      If (m_LogType = "M") Then
         strLogFile = m_LogDir & "\" & m_LogFile & "_" & strMonth & ".log"
      Else
         strLogFile = m_LogDir & "\" & m_LogFile & "_" & strDay & ".log"
      End If
      With OpenFile(strLogFile)
         .WriteLine(m_LogID & vbTab & Chr(34) & strLogDate & Chr(34) & vbTab & Chr(34) & strText & Chr(34))
         .Close
      End With
      Write = Err.Number
   End Function
   
End Class

'******************************************************************************************************************************
'********** CODE                                                                                                     **********
'******************************************************************************************************************************

Dim oApp : Set oApp = CreateObject("hMailServer.Application")
Call oApp.Authenticate(ADMIN, PASSWORD)
Dim EventLog : Set EventLog = CreateObject("hMailServer.EventLog")
Dim FSO : Set FSO = CreateObject("Scripting.FileSystemObject")
Dim EventLogX : Set EventLogX = New LogWriter
'
'   Name of the logfile.
'   Default is monthly logs, for daily logs add: EventLogX.LogType = "D"
'
EventLogX.LogFile = "checkstate"
If oApp.ServerState = 1 Then
   If (FSO.FolderExists(oApp.Settings.Backup.Destination & "\DataBackup")) Then
      EventLogX.Write("CheckState: Server is currently doing backup...")
   Else
      EventLogX.Write("CheckState: Server was stopped for no reason, starting...")
      Call oApp.Start
   End If
End If

'******************************************************************************************************************************
'********** END                                                                                                      **********
'******************************************************************************************************************************
Trying to understand this in context here. Jimi's backup script is (I think :?: ) totally different than the standard backup. In the standard backup, the server is paused, then backup performed then unpaused. Is that correct? Jimi's script does a complete shutdown, then runs robocopy on the data dir.

User avatar
SorenR
Senior user
Senior user
Posts: 3169
Joined: 2006-08-21 15:38
Location: Denmark

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by SorenR » 2019-02-18 18:42

palinka wrote:
2019-02-18 17:53
SorenR wrote:
2019-02-18 15:30
I run this monitor on my server via Scheduler every 10 minutes.

90% of the code is actually the logfile writer :roll:
The section "CODE" is where the action is.

I do a simple check here but this could easily be expanded to do the SMS thingy via API to a GSM device, a SMSC/MMSC connected to a GSM backboe or via The Internet to a HLR. If you should be so lucky to have your own SGSN, that would be even easier.

Code: Select all

If oApp.ServerState = 1 Then
   If (FSO.FolderExists(oApp.Settings.Backup.Destination & "\DataBackup")) Then
      EventLogX.Write("CheckState: Server is currently doing backup...")
   Else
      EventLogX.Write("CheckState: Server was stopped for no reason, starting...")
      Call oApp.Start
   End If
End If

Code: Select all

hStateStopped = 1, Server is stopped.
hStateStarting = 2, Server is starting.
hStateRunning = 3, Server is running.
hStateStopping = 4, Server is stopping.
Trying to understand this in context here. Jimi's backup script is (I think :?: ) totally different than the standard backup. In the standard backup, the server is paused, then backup performed then unpaused. Is that correct? Jimi's script does a complete shutdown, then runs robocopy on the data dir.
This is not a "backup script", it's a "Bigbrother's keeping an eye on my server" type script trying to figure out what it is doing and what should be done about it. Granted it is VERY simple but I have some ideas as I also experienced the "hung server" when server was paused before backup... once ... In hindsight I should have looked in the log as it was flooding with "CheckState: Server was stopped for no reason, starting..." every 10 minutes :roll:
SørenR.

The quantum rule of insecurity which states that the act of observing how vulnerable a host or service is changes the insecurity level of the service.

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-18 19:00

SorenR wrote:
2019-02-18 18:42

This is not a "backup script", it's a "Bigbrother's keeping an eye on my server" type script trying to figure out what it is doing and what should be done about it. Granted it is VERY simple but I have some ideas as I also experienced the "hung server" when server was paused before backup... once ... In hindsight I should have looked in the log as it was flooding with "CheckState: Server was stopped for no reason, starting..." every 10 minutes :roll:
I know it's not a backup script. I'm curious as to whether it would work with Jimi's backup script. I wouldn't want your script turning hmailserver back on in the middle of running Jimi's backup.

This hang happens to me once every month or two. Usually after installing software. At least that's what i think based on the fact it usually happens on a weekend and that's when i fool around with things usually. I will pay more attention next time it happens. Before this last time, i was installing gammu sms service which included installing a mysql odbc connector and rebooting a couple of times for different reasons. Now that install is up and running smoothly on a windows service.

I think a notify only version would be better for my purpose. Anyway, i put some effort and a few bucks into this sms thing and I want to use it. :mrgreen:

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-18 20:28

NET STOP is supposed to wait for confirmation that the service has stopped. I did a little research and found conflicting information.

a) NET STOP will not return any code until completed. If this is true, it makes sense insofar as the backup script cannot proceed until NET STOP finishes. It apparently never finished during the hang and would explain the short backup log - except that echo %time% Stopping Hmailserver service...>> %BackLog% comes before net stop hmailserver in the backup script. I would expect to see "Stopping Hmailserver service..." no matter what happens.

b) NET STOP will timeout at an interval set in your registry: \HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\WaitToKillServiceTimeout. Mine is set to 5000, which I think is in miliseconds, so 5 seconds.

There must be a way to make the shutdown foolproof. Some kind of timeout or something.

User avatar
SorenR
Senior user
Senior user
Posts: 3169
Joined: 2006-08-21 15:38
Location: Denmark

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by SorenR » 2019-02-18 23:28

It seems that it's been accounted for here...
:maildata
echo %time% Stopping Hmailserver service...>> %BackLog%&net stop hmailserver >> %BackLog%
set FailedHmailservice=Ok
set bold=%noBold%&set fontcolor=%fontBlack%
if errorlevel 1 set Failed=true&set FailedHmailservice=Failed to stop. Backup of emails not performed!&set bold=b&set fontcolor=%colorfill%
echo %FailedHmailservice%! >> %BackLog%
Someone else had a "hung service" ... Found this...
Click the Start menu
Click Run or in the search bar type services.msc
Press Enter
Look for the service and check the Properties and identify its service name
Once found, open a command prompt. Type sc queryex [servicename].
Press Enter
Identify the PID
In the same command prompt type taskkill /pid [pid number] /f
Press Enter
https://community.spiceworks.com/how_to ... ng-service

https://ss64.com/nt/taskkill.html

Hmm... I must have installed something at some point, I have BOTH taskkill AND tskill - on my Windows XP Pro SP3 :mrgreen:

Now, if the task you want to perform should be monitored by a "BigBrother App", you need for it to create/delete "flags" or files that the monitoring script can work with. Based on the "age" of the flag certain steps should be taken.

It is quite common with real-time mission critical applications to have a BigBrother App watching over it. Just in case the Mother App is killed, failes or hangs.
SørenR.

The quantum rule of insecurity which states that the act of observing how vulnerable a host or service is changes the insecurity level of the service.

User avatar
jimimaseye
Moderator
Moderator
Posts: 8066
Joined: 2011-09-08 17:48

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by jimimaseye » 2019-02-19 00:43

I have to say, it is strange. Your script is the same as mine and I never have these shutdown issues. The app is paused ('oApp.stop') and yet from your log file you had a strange interuption:

Code: Select all

"DEBUG"	5604	"2019-02-16 23:58:02.569"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
It is made stranger by the fact that it doesnt even get to the service STOP command (back to the Bat file) as evident by the missing echo command in the log file.

I use taskkill at work and it does what it is designed to. HOWEVER, during last years weird Windows Update that prevented hmailserver service from stopping, even TASKKILL was unable to kill it (despite the program/service being visible). Given that you are experiencing strange failures to stop the service you could try "taskkill /im hmailserver.exe" as part of the 'if errorlevel 1...' statement (where Soren identified) but I wouldnt want to bet on it being a guarantee because I dont think it even gets to that part of the Bat file.

My advice: remove the oApp.stop command from serverstatusreport.vbs and see how you get on for the next month.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

palinka
Senior user
Senior user
Posts: 945
Joined: 2017-09-12 17:57

Re: HOW TO: Ready-To-Go Backup and Cleardown script

Post by palinka » 2019-02-19 00:55

jimimaseye wrote:
2019-02-19 00:43
I use taskkill at work and it does what it is designed to. HOWEVER, during last years weird Windows Update that prevented hmailserver service from stopping, even TASKKILL was unable to kill it (despite the program/service being visible). Given that you are experiencing strange failures to stop the service you could try "taskkill /im hmailserver.exe" as part of the 'if errorlevel 1...' statement (where Soren identified) but I wouldnt want to bet on it being a guarantee because I dont think it even gets to that part of the Bat file.

My advice: remove the oApp.stop command from serverstatusreport.vbs and see how you get on for the next month.
I think you're right about that. Actually, adding oApp.stop reduced the frequency of the hangs. I think I'll hold on to it for the moment. Thankfully, its not an everyday occurrance. Usually once every month or two, although the last time before this one was only a couple of weeks ago.

One thing is for sure - I'm going to find some method of determining service state and look at this issue a little closer next time before I go ahead and reboot.

Post Reply