Cannot fetch new mails

[helmutchecker]

I want to write a method to wait for an incoming mails matching a given search Filter. Therefore, I am using service.FindItems to fetch items in a loop each 5 seconds. Unfortunately, it finds existing mails and prints e.g. count 8 every 5 seconds, but when a new mail with same matching search criteria is received, it is not registered and count stays at 8.

After restarting the code, the initial count is then 9 and when receiving new mails, it is staying at 9 until I restart the code.

Did I misunderstand something about how the library should be working, or do I need to follow a different approach?

[bladerunner2020]

Did I misunderstand something about how the library should be working, or do I need to follow a different approach?

It’s difficult to say without seeing your code. Could you share some examples?

[helmutchecker]

As described, I am planning to wait for an incoming mail that should be received in the next 30 seconds e.g.
The logline Total items found: returns always the same amount, even though a new mail is received in the meantime, when re-running, it shows the correct new value, so basic detection etc. should be working.

async waitForEmail(receivedAfter: Dayjs, containsHeader: string, containsBody: string, timeoutMs: number) {
    const searchFilter = new SearchFilter.SearchFilterCollection(LogicalOperator.And, [
      new SearchFilter.IsGreaterThanOrEqualTo(
        ItemSchema.DateTimeReceived,
        DateTime.Parse(receivedAfter.format("YYYY-MM-DDTHH:mm:ss"))
      ),
      new SearchFilter.ContainsSubstring(ItemSchema.Subject, containsHeader),
      new SearchFilter.ContainsSubstring(ItemSchema.Body, containsBody),
    ]);

    const dateTimeStarted = dayjs();
    let emails: Email[] = [];
    while (emails.length < 1) {
      const dateTimeNow = dayjs();
      if (dateTimeStarted.add(timeoutMs, "milliseconds").isBefore(dateTimeNow)) {
        throw new MailReceiveTimeoutError(dateTimeStarted, dateTimeNow, timeoutMs);
      }
      try {
        emails = await this.fetchMails(searchFilter, 1);
      } catch (err) {
        if (err instanceof NotEnoughMailsError) {
          await sleep(5_000);
          continue;
        } else {
          throw err;
        }
      }
    }

    return emails;
  }

  async fetchMails(searchFilter: SearchFilter, count: number) {
    // Define a view to limit the number of items returned
    const view = new ItemView(count);

    // Set the properties you want to load
    view.PropertySet = new PropertySet(ItemSchema.Subject, ItemSchema.DateTimeReceived);

    // Find items in the inbox
    const findResults = await this.service.FindItems(this.folder, searchFilter, view);
    this.logger.logMessage(`Total items found: ${findResults.TotalCount}`);

    if (findResults.TotalCount < count) {
      throw new NotEnoughMailsError(count, findResults.TotalCount);
    }

    const emails: Email[] = [];
    // Load additional properties of the items if needed
    await this.service.LoadPropertiesForItems(findResults.Items, PropertySet.FirstClassProperties);
    for (const item of findResults.Items) {
      emails.push(parseEmail(item));
    }
    return emails;
  }

[gautamsi]

are you able to log searchFilter in fetchMails so that you know the filter is correct? if you are rerunning this and the email comes, it may be filter calculation issue.

[helmutchecker]

I was using current time -100 minutes to ensure the time frame is matching and prepared 2 mails that are fetched. After starting the code waiting for 3 messages, I submitted another mail which was received correctly, but not noticed by the code. After restarting, the 3 messages are found correctly. Please find the log with searchFilter here:

# first run
2025-01-09 18:14:33.554 - worker-26: {"Namespace":2,"OnChange":[],"searchFilters":[{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:DateTimeReceived","name":"DateTimeReceived","xmlElementName":"DateTimeReceived","flags":32,"version":0,"isNullable":false},"value":{"kind":0,"originalDateInput":"2025-01-09T16:33:57"}},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Subject","name":"Subject","xmlElementName":"Subject","flags":60,"version":0,"isNullable":false},"value":"subject","containmentMode":2,"comparisonMode":1},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Body","name":"Body","xmlElementName":"Body","flags":28,"version":0},"value":"body","containmentMode":2,"comparisonMode":1}],"logicalOperator":0}
2025-01-09 18:14:33.644 - worker-26: Total items found: 2
2025-01-09 18:14:38.645 - worker-26: {"Namespace":2,"OnChange":[],"searchFilters":[{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:DateTimeReceived","name":"DateTimeReceived","xmlElementName":"DateTimeReceived","flags":32,"version":0,"isNullable":false},"value":{"kind":0,"originalDateInput":"2025-01-09T16:33:57"}},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Subject","name":"Subject","xmlElementName":"Subject","flags":60,"version":0,"isNullable":false},"value":"subject","containmentMode":2,"comparisonMode":1},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Body","name":"Body","xmlElementName":"Body","flags":28,"version":0},"value":"body","containmentMode":2,"comparisonMode":1}],"logicalOperator":0}
2025-01-09 18:14:38.724 - worker-26: Total items found: 2
2025-01-09 18:14:43.725 - worker-26: {"Namespace":2,"OnChange":[],"searchFilters":[{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:DateTimeReceived","name":"DateTimeReceived","xmlElementName":"DateTimeReceived","flags":32,"version":0,"isNullable":false},"value":{"kind":0,"originalDateInput":"2025-01-09T16:33:57"}},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Subject","name":"Subject","xmlElementName":"Subject","flags":60,"version":0,"isNullable":false},"value":"subject","containmentMode":2,"comparisonMode":1},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Body","name":"Body","xmlElementName":"Body","flags":28,"version":0},"value":"body","containmentMode":2,"comparisonMode":1}],"logicalOperator":0}
2025-01-09 18:14:43.923 - worker-26: Total items found: 2



# second run
2025-01-09 18:16:17.245 - worker-27: {"Namespace":2,"OnChange":[],"searchFilters":[{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:DateTimeReceived","name":"DateTimeReceived","xmlElementName":"DateTimeReceived","flags":32,"version":0,"isNullable":false},"value":{"kind":0,"originalDateInput":"2025-01-09T16:36:17"}},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Subject","name":"Subject","xmlElementName":"Subject","flags":60,"version":0,"isNullable":false},"value":"subject","containmentMode":2,"comparisonMode":1},{"Namespace":2,"OnChange":[null],"propertyDefinition":{"uri":"item:Body","name":"Body","xmlElementName":"Body","flags":28,"version":0},"value":"body","containmentMode":2,"comparisonMode":1}],"logicalOperator":0}
2025-01-09 18:16:17.600 - worker-27: Total items found: 3

[gautamsi]

enable debugging by adding code after import from this lib

EwsLogging.DebugLogEnabled = true;

this way it will print log of xml messages, see if you find something or give me that

[bladerunner2020]

It’s strange. It seems like EWS is caching the search results or something similar. I would try the following: (a) create a new filter for each search, (b) add 1 second to the receivedAfter time after each iteration, and (c) increase the number of items, say, to 10.

[helmutchecker]

The log was not helpful unfortunately, everything looks good.

I also applied the mentioned 3 changes. It could be really some kind of caching. When applying the new datetime minus 100 minutes on each call, it suddenly starts receiving the new mails, but only with a delay. All this still looks very strange to me.

[bladerunner2020]

That's weird. As I found out, it does find new emails - findResults.Items[0] contains the new email. However, the TotalCount indeed remains unchanged.

Here is the code to reproduce this behavior:

const {
  ExchangeService, WebCredentials, PropertySet, ItemSchema, ItemView, SearchFilter, WellKnownFolderName, Uri,
} = require('ews-javascript-api');

const credentials = require('./credentials.json');

const exch = new ExchangeService(credentials.exchangeVersion);
exch.Credentials = new WebCredentials(credentials.username, credentials.password);
exch.Url = new Uri(credentials.url); 

async function searchEmails() {
  const view = new ItemView(10);
  view.PropertySet = new PropertySet(ItemSchema.Subject, ItemSchema.DateTimeReceived);

  const searchFilter = new SearchFilter.ContainsSubstring(ItemSchema.Subject, 'test');
  
  try {
    const findResults = await exch.FindItems(WellKnownFolderName.Inbox, searchFilter, view);
    console.log(`Found ${findResults.TotalCount} emails`);
    // findResults.Items.forEach(item => {
    //   console.log(`Subject: ${item.Subject}, DateTimeReceived: ${item.DateTimeReceived}`);
    // });
  } catch (error) {
    console.error('Error searching emails:', error);
  }
}

setInterval(() => {
  searchEmails();  
}, 30000);

[helmutchecker]

Thank you for investigation, you seem to be right. TotalCount is not working correct, I also managed to get a negative value today. For my use case it works to use findResults.Items.length and compare it with the expected length (though this is capped to the view count).

So for me I it is ok to work with the workaround, but still it would be good to get the TotalCount fixed.

[bladerunner2020]

I checked the SOAP requests generated by this library, and they seem legit. It looks like this might be a bug or feature of Microsoft's EWS...

[gautamsi]

@bladerunner2020 did you find any issue in updating TotalCount from subsequent response or the value is incorrect from MS side?

[bladerunner2020]

@bladerunner2020 did you find any issue in updating TotalCount from subsequent response or the value is incorrect from MS side?

As far as I’ve found, Microsoft’s response contains an incorrect TotalCount value. Even when I create a new instance of ExchangeService on each request, the value remains unchanged. It seems there might need to be a delay between calls, but I haven’t figured it out yet.

Here’s the request envelope:

<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"
  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
  xmlns:m="http://schemas.microsoft.com/exchange/services/2006/messages"
  xmlns:t="http://schemas.microsoft.com/exchange/services/2006/types">
  <soap:Header>
    <t:RequestServerVersion Version="V2015_10_05"></t:RequestServerVersion>
  </soap:Header>
  <soap:Body>
    <m:FindItem Traversal="Shallow">
      <m:ItemShape>
        <t:BaseShape>IdOnly</t:BaseShape>
        <t:AdditionalProperties>
          <t:FieldURI FieldURI="item:Subject"></t:FieldURI>
          <t:FieldURI FieldURI="item:DateTimeReceived"></t:FieldURI>
        </t:AdditionalProperties>
      </m:ItemShape>
      <m:IndexedPageItemView MaxEntriesReturned="1" Offset="0" BasePoint="Beginning"></m:IndexedPageItemView>
      <m:Restriction>
        <t:Contains ContainmentMode="Substring" ContainmentComparison="IgnoreCase">
          <t:FieldURI FieldURI="item:Subject"></t:FieldURI>
          <t:Constant Value="latest"></t:Constant>
        </t:Contains>
      </m:Restriction>
      <m:ParentFolderIds>
        <t:DistinguishedFolderId Id="inbox"></t:DistinguishedFolderId>
      </m:ParentFolderIds>
    </m:FindItem>
  </soap:Body>
</soap:Envelope>

Response:

<?xml version="1.0" encoding="utf-8"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
  <s:Header>
    <h:ServerVersionInfo MajorVersion="15" MinorVersion="2" MajorBuildNumber="1544"
      MinorBuildNumber="14" Version="V2017_07_11"
      xmlns:h="http://schemas.microsoft.com/exchange/services/2006/types"
      xmlns="http://schemas.microsoft.com/exchange/services/2006/types"
      xmlns:xsd="http://www.w3.org/2001/XMLSchema"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" />
  </s:Header>
  <s:Body xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:xsd="http://www.w3.org/2001/XMLSchema">
    <m:FindItemResponse xmlns:m="http://schemas.microsoft.com/exchange/services/2006/messages"
      xmlns:t="http://schemas.microsoft.com/exchange/services/2006/types">
      <m:ResponseMessages>
        <m:FindItemResponseMessage ResponseClass="Success">
          <m:ResponseCode>NoError</m:ResponseCode>
          <m:RootFolder IndexedPagingOffset="1" TotalItemsInView="3" IncludesLastItemInRange="false">
            <t:Items>
              <t:Message>
                <t:ItemId
                  Id="AQMkADQ5ZTQ5NTE3LWExZDItNDM2ZC05NDVlLTZlNTk3M2Q3OWM0NgBGAAAD/nxyUaRXOEOci+3WZu9dewcA0URrlxo4Jky9H9PJlZEgewAAAgEMAAAA0URrlxo4Jky9H9PJlZEgewABIEWrwQAAAA=="
                  ChangeKey="CQAAABYAAADRRGuXGjgmTL0f08mVkSB7AAEgSrNT" />
                <t:Subject>latest something #01</t:Subject>
                <t:DateTimeReceived>2025-01-14T11:27:58Z</t:DateTimeReceived>
              </t:Message>
            </t:Items>
          </m:RootFolder>
        </m:FindItemResponseMessage>
      </m:ResponseMessages>
    </m:FindItemResponse>
  </s:Body>
</s:Envelope>

The current TotalCount value should be 4. In fact, I received this value when I ran the program some time ago. The request envelope was the same, and the only difference in the response was the TotalCount value.

[bladerunner2020]

@helmutchecker You might want to try using SyncFolderItems instead of FindItems, by the way.