Close all nineteen discarded write and load results, and four more defects with them

The prerequisite row has called ignored return values the most serious class of defect
in this tree for a while, and then listed two NUL truncations as what was left. That
list was wrong. Counted rather than estimated, there were nineteen call sites that
discarded the result of a write or a load, and this closes every one.

WHY THEY GOT WORSE THIS MORNING BEFORE THEY GOT BETTER

Twelve of the nineteen are `MessageData::Write`. Until today a failed Write produced a
message with no body and returned true, so those twelve wrote a broken message and
carried on. This morning's MIME work made Write refuse rather than commit a body-less
message - which is correct, and which turned all twelve into silent no-ops: the header
a rule set, the trace header on a local delivery, the vacation body, the virus
notification simply do not get written and delivery continues as though they had.

That is the shape worth naming. Fixing a layer properly can make the defects above it
LESS visible rather than more, and the twelve were about to disappear into "works
fine". They now go through `MessageData::WriteReported`, which reports what has not
been written and names it.

Four of the twelve are not modifications of an existing message but the FIRST write of
one built from nothing - a rule-generated reply, a delivery-failure notification, an
out-of-office reply, a virus notification. For those, discarding the result queued a
message row whose file does not exist and left the delivery to trip over it. They now
abort: no reply at all is better than a reply the recipient can never read, and each of
those functions already returned early on other conditions.

THE OTHER SEVEN, EACH HANDLED THE WAY ITS OWN SURROUNDINGS ALREADY HANDLE FAILURE

`VirusScanner` had two, and they were the ones with teeth. The scanner makes two passes
- the whole file, then each attachment separately, because a scanner that does not
decode MIME will not see inside a base64 part. Both inputs to the second pass were
taken on trust: a message that could not be parsed produced an EMPTY attachment list,
so the loop ran over nothing and the function returned "no virus found"; and a failed
temp-file write left `ScanFile_` scanning a file that was missing or empty, which comes
back clean. Neither is unscanned mail - the whole file is scanned first - which is why
these report (6001, 6002) rather than refusing the message. Refusing on a transient
file lock would turn a degraded scan into rejected mail.

`SpamAssassinClient` counted bytes it had not written, so a short write could satisfy
the length check and hand back a truncated message to replace the original. It now
aborts the response, which is exactly what the two other failure paths in that function
already do.

`MessageAttachmentStripper` rewrites a message from what it read, and read it without
checking. Its outcome was accidentally safe rather than deliberately so - it depended on
FindFirstPart returning nothing for an empty parse - so it now says what happened and
leaves the file alone.

`Attachment::SaveAs` is reached from COM, where a script has just been told the save
worked. It is void, so a full disk looked exactly like success and the script moved on
to the next attachment. Reported as 6003.

`IMAPFetch` answered the client from an empty body when the load failed: a message that
renders blank, with an OK, which the client then caches and stops asking for. Now
reported. Be clear about what that does not fix - `ReportCriticalError_` says in its own
comment that it reports "and then throws an exception", and it does not throw, so the
blank message still goes out. That is written up rather than changed, because making it
throw alters the failure semantics of every FETCH and wants its own test.

`Logger`'s two are the one failure in the server that cannot be logged: LOG_APPLICATION
comes straight back, and ErrorManager writes the error log through the same function, so
on the failing disk that provokes it the report would re-enter what just failed, once
per line. They go once per process to the debugger and the Windows event log instead. A
mail server whose audit trail has silently stopped used to look exactly like a quiet
one.

FOUR MORE, FOUND WHILE DOING IT

`Event::WaitFor` returned void - with a comment beside the discarded result reading
"result will be false if there's a timeout". A caller could bound a wait and not be told
which of the two happened, which is the entire point of bounding it. The predicate form
also fixes a quieter bug: a bare `wait_for` returns on a spurious wakeup too, and the
old code then cleared the flag and carried on as though the event had fired.

That was the missing piece for `ExternalFetch::Start`, which ended in an UNBOUNDED wait
on a work-queue thread, set only by `~TCPConnection`, with the POP3 client setting an
idle timeout and no absolute ceiling. A remote server sending one byte before each
expiry held that fetch thread indefinitely; enough accounts in that state and external
fetching stops for every account on the server. The fix is not just a timeout: `Start`
drops its reference to the connection before waiting, so timing out would return while
the session is still live and let the next cycle collect the same mailbox concurrently -
the duplicate-delivery shape half of today was spent removing. It keeps a weak reference
and disconnects what it abandons, through `EnqueueDisconnect` so the shutdown is posted
to the strand that owns the socket rather than called across threads. One hour, chosen as
a backstop for the pathological case and not as a performance bound.

`SqlLogDevice` sent `PRIMARY KEY CLUSTERED` to SQL CE, which does not accept it. Every
constraint in the script SQL CE actually runs is NONCLUSTERED, and the one CLUSTERED
form in it is stripped by `SQLScriptParser::PreprocessLine_` before SQL CE sees it -
these statements do not go through that parser. It failed invisibly because the line
carries `[IGNORE-ERRORS]`, so on the installer's DEFAULT backend the SQL log device has
been running without a primary key on hm_log for as long as this has been there.

`ScheduledTask::SetNextRunTime` computed "now + interval" after the task returned, so
the real period was interval plus however long the task took and every pass drifted by
its own duration. Nothing was ever skipped, so nothing ever looked wrong - the runs just
wandered away from the times the administrator set. Now measured from the run that was
due, with a guard so a task that overran its own interval resumes the cadence instead of
running back-to-back to catch up.

VERIFICATION

Release build clean. Full suite green.

Author: chrisholloway5

Roadmap.md

@@ -179,9 +179,22 @@ namespace HM
          }
       }
 
-      // Append output to the file
+      // Append output to the file.
+      //
+      // The result was discarded, and this file becomes the message: a failed or short
+      // write left total_result_bytes_written_ counting bytes that are not on disk, so
+      // the length check below could be satisfied by a file that is truncated, and
+      // SpamAssassin's rewritten message would replace the original minus whatever did
+      // not get written. Aborting keeps the original message, which is what the two
+      // other failure paths in this function already do.
       size_t written_bytes = 0;
-      result_->Write(pBuf, written_bytes);
+
+      if (!result_->Write(pBuf, written_bytes))
+      {
+         LOG_DEBUG("SA: the response could not be written to disk; keeping the original message.");
+         AbortResponse_();
+         return;
+      }
 
       total_result_bytes_written_ += written_bytes;
 

hmailserver/source/Server/Common/AntiSpam/SpamAssassin/SpamAssassinClient.cpp

@@ -141,7 +141,7 @@ namespace HM
          // The Return-Path header was added above to help SpamAssassin with its SPF checks.
          // We should remove it again to restore the headers to original state (except for any added by SA).
          pMessageData->DeleteField("Return-Path");
-         pMessageData->Write(sFilename);
+         pMessageData->WriteReported(sFilename, "The removal of the Return-Path header added for SpamAssassin's SPF checks");
       }
       else
       {

hmailserver/source/Server/Common/AntiSpam/SpamTestSpamAssassin.cpp

@@ -215,9 +215,26 @@ namespace HM
       }
 
 
-      // Read message, extract attachments, 
+      // Read message, extract attachments,
       std::shared_ptr<MimeBody> pMimeBody = std::shared_ptr<MimeBody>(new MimeBody);
-      pMimeBody->LoadFromFile(sLongFilename);
+
+      // The result used to be discarded, and a message that could not be parsed then
+      // produced an EMPTY attachment list - so this second pass silently scanned
+      // nothing and the message was reported clean by it. The whole file has already
+      // been scanned above, so this is not "delivered unscanned"; what is lost is the
+      // per-attachment pass, which is the one that matters for a scanner that does not
+      // decode MIME itself. Reported rather than made fatal: refusing the message on a
+      // transient file lock would turn a degraded scan into rejected mail.
+      const MimeLoadResult loadResult = pMimeBody->LoadFromFile(sLongFilename);
+
+      if (loadResult != MimeLoadResult::Loaded)
+      {
+         ErrorManager::Instance()->ReportError(ErrorManager::Medium, 6001, "VirusScanner::Scan",
+            Formatter::Format("The message {0} could not be parsed for per-attachment virus scanning, so only the whole message file was scanned. Any attachment the scanner cannot decode by itself has therefore not been examined separately.",
+               sLongFilename));
+
+         return false;
+      }
 
       std::list<std::shared_ptr<MimeBody> > oList;
       pMimeBody->GetAttachmentList(pMimeBody, oList);
@@ -230,7 +247,20 @@ namespace HM
 
          // Create a temporary filename.
          sLongFilename.Format(_T("%s\\%s.tmp"), IniFileSettings::Instance()->GetTempDirectory().c_str(), GUIDCreator::GetGUID().c_str());
-         pBody->WriteToFile(sLongFilename);
+
+         // Likewise discarded before this. A failed write leaves the temp file missing
+         // or empty and ScanFile_ then scans that - and reports it clean, which is the
+         // scanner agreeing that nothing is wrong with a file it never saw.
+         if (!pBody->WriteToFile(sLongFilename))
+         {
+            ErrorManager::Instance()->ReportError(ErrorManager::Medium, 6002, "VirusScanner::Scan",
+               Formatter::Format("An attachment of {0} could not be written to {1} for scanning, so it has not been examined. The rest of the message has been.",
+                  PersistentMessage::GetFileName(pMessage), sLongFilename));
+
+            FileUtilities::DeleteFile(sLongFilename);
+            iter++;
+            continue;
+         }
 
          VirusScanningResult result = ScanFile_(sLongFilename);
          if (result.GetVirusFound())
@@ -305,8 +335,8 @@ namespace HM
 
       if (changes_made)
       {
-         message_data->Write(file_name);
-            
+         message_data->WriteReported(file_name, "The removal of virus-bearing attachments");
+
          // Update the size of the message.
          message->SetSize(FileUtilities::FileSize(file_name));
       }

hmailserver/source/Server/Common/AntiVirus/VirusScanner.cpp

@@ -595,9 +595,14 @@ namespace HM
          break;
       }
 
+      // Both Write results below are checked through ReportWriteFailure_. They cannot be
+      // reported the ordinary way: LOG_APPLICATION and ErrorManager both end up back
+      // here, so a disk that has stopped accepting writes would recurse through the
+      // thing that just failed. See ReportWriteFailure_.
       if (writeUnicode)
       {
-         file->Write(sData);
+         if (!file->Write(sData))
+            ReportWriteFailure_(file->GetName());
       }
       else
       {
@@ -616,13 +621,52 @@ namespace HM
             sAnsiString = sData.Mid(0, max_log_line_len_ - 30) + " ... " + sData.Mid(iDataLenTmp - 25);
             // We keep 25 of end which includes crlf but need to account for middle ... too
 
-         file->Write(sAnsiString);
+         if (!file->Write(sAnsiString))
+            ReportWriteFailure_(file->GetName());
       }
 
       if (!keepFileOpen)
          file->Close();
    }
 
+   void
+   Logger::ReportWriteFailure_(const String &fileName)
+   //---------------------------------------------------------------------------
+   // DESCRIPTION:
+   // A log line could not be written to disk.
+   //
+   // This is the one failure in the server that cannot be logged. LOG_APPLICATION
+   // comes straight back here, and ErrorManager::ReportError writes the error log
+   // through this same function - so on a full or failing disk, which is precisely
+   // when this fires, the report would re-enter the thing that just failed and do
+   // it once per line.
+   //
+   // So it goes to the debugger and the Windows event log, once per process. Once,
+   // because the condition is not transient and per-line reporting would itself be
+   // the flood; and to the event log because that is the one sink that is not this
+   // one. The result used to be discarded entirely, which meant a mail server whose
+   // audit trail had silently stopped looked exactly like a quiet one.
+   //---------------------------------------------------------------------------
+   {
+      static boost::once_flag reported = BOOST_ONCE_INIT;
+
+      boost::call_once(reported, [&fileName]()
+      {
+         String message = Formatter::Format("hMailServer could not write to its log file {0}. Logging has stopped, or is incomplete, from this point. This is reported once per run and cannot be written to the log itself.", fileName);
+
+         OutputDebugString(message);
+
+         HANDLE eventSource = RegisterEventSource(NULL, _T("hMailServer"));
+
+         if (eventSource != NULL)
+         {
+            LPCTSTR strings[1] = { message.c_str() };
+            ReportEvent(eventSource, EVENTLOG_ERROR_TYPE, 0, 0, NULL, 1, 0, strings, NULL);
+            DeregisterEventSource(eventSource);
+         }
+      });
+   }
+
 
    String
    Logger::GetCurrentTime()

hmailserver/source/Server/Common/Application/Logger.cpp

@@ -199,6 +199,10 @@ namespace HM
 
       void LogLive_(String &sMessage);
       void WriteData_(const String &sData, LogType = Normal);
+
+      // A log line that could not be written cannot be reported through the log. Once
+      // per process, to the debugger and the Windows event log. See the definition.
+      void ReportWriteFailure_(const String &fileName);
 
       String log_dir_;
       String GetCurrentTime();

hmailserver/source/Server/Common/Application/Logger.h

@@ -801,7 +801,16 @@ namespace HM
             _T(") --- [IGNORE-ERRORS]"));
 
          statements.push_back(
-            _T("ALTER TABLE hm_log ADD CONSTRAINT hm_log_pk PRIMARY KEY CLUSTERED (logid) --- [IGNORE-ERRORS]"));
+            // NONCLUSTERED, matching every constraint in CreateTablesMSSQL.sql - which is
+            // the script SQL CE actually runs, per DatabaseSettings::GetDefaultScript.
+            // This said CLUSTERED, which SQL CE does not accept. The one CLUSTERED form in
+            // that script is a CREATE CLUSTERED INDEX, and SQLScriptParser::PreprocessLine_
+            // strips the word out before SQL CE ever sees it; these statements do not go
+            // through that parser, so it reached the provider verbatim and the statement
+            // failed. It failed INVISIBLY, because the line carries [IGNORE-ERRORS] - so
+            // on the installer's default backend the SQL log device has been running
+            // without a primary key on hm_log for as long as this has been here.
+            _T("ALTER TABLE hm_log ADD CONSTRAINT hm_log_pk PRIMARY KEY NONCLUSTERED (logid) --- [IGNORE-ERRORS]"));
 
          statements.push_back(
             _T("CREATE INDEX idx_hm_log_logtime ON hm_log (logtime) --- [IGNORE-ERRORS]"));

hmailserver/source/Server/Common/Application/SqlLogDevice.cpp

@@ -30,7 +30,16 @@ namespace HM
    void
    Attachment::SaveAs(const String &sSaveTo) const
    {
-      attachment_->WriteToFile(sSaveTo);
+      // Reached from COM (IInterfaceAttachment::SaveAs), where the caller is a script
+      // or an administration tool that has just been told the save worked. The result
+      // was discarded and the method is void, so a failed write - a full disk, a path
+      // that cannot be created, a body that could not be read back - looked exactly
+      // like a successful one and the script carried on to the next attachment.
+      if (!attachment_->WriteToFile(sSaveTo))
+      {
+         ErrorManager::Instance()->ReportError(ErrorManager::Medium, 6003, "Attachment::SaveAs",
+            Formatter::Format("The attachment could not be written to {0}. The caller has not been told, because this method cannot report it; the file is either missing or incomplete.", sSaveTo));
+      }
    }
 
    String 

hmailserver/source/Server/Common/BO/Attachment.cpp

@@ -832,7 +832,29 @@ namespace HM
       return true;
    }
 
-   bool 
+   bool
+   MessageData::WriteReported(const String &fileName, const String &description)
+   //---------------------------------------------------------------------------
+   // DESCRIPTION:
+   // Write, reporting the failure rather than discarding it. See the header.
+   //
+   // LOG_APPLICATION and not ReportError: Write has already reported the cause at
+   // High with the specific reason (6010 or 6011), and a second ERROR record for
+   // the same event would say nothing new while doubling the chance of tripping a
+   // fixture that asserts a clean error log. What is added here is the thing Write
+   // cannot know - which piece of work has silently not been done.
+   //---------------------------------------------------------------------------
+   {
+      if (Write(fileName))
+         return true;
+
+      LOG_APPLICATION(Formatter::Format("{0} could not be written to {1}. The message has been left as it was and delivery has continued, so that change is not present in it.",
+                                        description, fileName));
+
+      return false;
+   }
+
+   bool
    MessageData::GetHasBodyType(const String &sBodyType)
    {
       std::shared_ptr<MimeBody> pPart = FindPart(sBodyType);      
@@ -964,7 +986,7 @@ namespace HM
       String fileName = PersistentMessage::GetFileName(account, pMessage);
 
       // Write it
-      pMsgData->Write(fileName);
+      pMsgData->WriteReported(fileName, "The self-test message");
 
 
       // Save it

hmailserver/source/Server/Common/BO/MessageData.cpp

@@ -71,6 +71,18 @@ namespace HM
 
       bool Write(const String &fileName);
 
+      // Write, and report it if it fails, naming what the caller was trying to write.
+      //
+      // Twelve call sites across rules, forwarding, vacation, virus notification, the
+      // SpamAssassin pass and the attachment stripper discarded Write's result. That was
+      // survivable while a failed Write still produced a file - it produced the WRONG
+      // file, a message with no body, which is the defect Write now refuses to commit.
+      // Refusing made those twelve quieter rather than correct: the header, the trace
+      // line, the vacation body simply does not get written and delivery carries on as
+      // though it had. None of them can do anything useful about the failure, so this
+      // exists to make sure none of them can hide it either.
+      bool WriteReported(const String &fileName, const String &description);
+
       int GetSize() const;
 
       std::shared_ptr<Attachments> GetAttachments();