Spam not Filtered when Outlook in background

Running Outlook 2011 14.4.5 on MacOS 10.9.5 and SpamSieve 2.9.17. When Outlook has been in the background and downloading email, when I come back to it, there are a bunch of spam messages in my inbox. If I run the SpamSieve rules on these messages, they are properly identified as spam and moved to the spam folder. So I know the rules work properly. The SpamSieve Set Category, Move Junk, and Move Junk Suspected are the first three rules in my rule list in Outlook.

If Outlook is in the foreground (the active application), new spam messages get processed correctly and automatically.

Any idea why the rules aren’t being processed when Outlook is in the background?

I’ve never heard of Outlook rules working differently when the app is in the foreground or background. Please check the mailing list manager, as that can prevent rules from being applied automatically.

Nope, nothing was set in Mailing List Manager.

Can you tell from SpamSieve’s log whether the rules are in fact not being applied? That is, are there no “Predicted:” entries added when it’s in the background?

If I come back to Outlook and find a couple spammy messages at the top of my regular inbox, I check the log and they are not listed. If I then “apply all rules” to those messages, they are moved to the spam folder and they then appear in the SpamSieve log as predicted spam.

This is an Exchange account. I wonder if that has anything to do with it?

But you are saying that other messages from that same account are automatically predicted as spam?

If Outlook thinks that Exchange (or IMAP) messages are not new, it won’t automatically apply the rules to them. Are the messages perhaps being read on another device before Outlook sees them?

Yes, other messages are if Outlook is in the foreground. And these messages are once I manually apply the rules to them. (It’s not a matter of whether SS thinks they’re spam, it’s whether the rules get applied.

If Outlook thinks that Exchange (or IMAP) messages are not new, it won’t automatically apply the rules to them. Are the messages perhaps being read on another device before Outlook sees them?

Good point. My phone is always on and getting the email pushed from the Exchange server. But I’m not reading the messages on the phone first. Nor is the iPhone mail app even in the foreground on the phone.

It sounds like everything is fine with your Outlook setup and SpamSieve. You could try narrowing down the list of other devices that have access to that mail account by shutting them off (completely, not just sleep). For example, I have seen older iOS devices mark messages as read even when the Mail app stayed in the background. If you are sure that only your Mac is accessing the account, then I would suggest reporting this to Microsoft as a bug in Outlook.

More info…
It’s been a few months and I’ve been watching this to try to narrow it down. I’ve removed all rules in the local rule set except the three SpamSieve rules plus one more, after those three, that marks messages with a category “Not in Contacts” if the sender is not in Outlook’s contacts.

As and example of what happens when I first fire up Outlook in the morning… I receive a large number of messages. As I watch them get processed (Outlook in the foreground), I can see some being marked and moved to the Junk folder. I will see some others get marked “Not in Contacts” but not moved even though they look like junk. This tells me that the rules were processed and got down the the final rule, but somehow SpamSieve didn’t mark the message.

However, if after all this, I select these messages and Apply All Rules, SpamSieve then marks and moves the messages to the Junk folder.

So it appears that the first SpamSieve rule is somehow skipping some messages on the first pass, even though it marks them when the rule is re-applied.

Is there a log file that we can capture when this occurs to get a better idea what’s going on? I could record the screen on morning startup if that helps.

I’m not aware of any Outlook-specific rule log, although perhaps if you contact Microsoft they will be able to suggest something. The SpamSieve log shows all the messages that SpamSieve received for analysis. If you look in the system Console log at the right time, it’s possible that you would see error messages from Outlook or SpamSieve’s “Set Category” script about messages that it wasn’t able to process. I plan to add additional error logging to the script in the next version.

Here’s an example from the logs: Time now about 14:48 local, 19:48 UTC. There was a message still in my inbox subject: “Can this 10 Second Trick Help Prevent YOUR Heart Attack?”. It was not moved to Junk by SpamSieve’s rules, but the Not in Contacts category was applied by the last rule. Looking in the error logs, I see this message:


2/11/15 13:21:44.169 rick[6080]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Can this 10 Second Trick Help Prevent YOUR Heart Attack?

And there was nothing matching this message in SpamSieve’s log. Then, I did an Apply All Rules to that message. At that point, the SpamSieve rules marked it as spam and moved it to Junk. And the following appeared in SpamSieve’s log: (again, only after the 2nd application of the rules)


Predicted: Spam (96)
Subject: Can this 10 Second Trick Help Prevent YOUR Heart Attack?
From: [email]webmaster@diaereses.jartic.us[/email]
Identifier: yiCGJ0iwLp9aPoWmnTwZmg==
Reason: P(spam)=1.000[1.000], bias=0.267, ^fes-jpg-18(1.000), U:0Bib(1.000), U:0Bib(1.000), I:unsub(1.000), RP:info@(1.000), C:time(1.000), C:time(1.000), C:one(1.000), C:one(1.000), C:we(1.000), C:browser(1.000), C:every(1.000), C:every(1.000), C:than(1.000), C:than(1.000)
Date: 2015-02-11 19:47:53 +0000

So clearly the rules are being invoked, but for some reason SpamSieve is not able to get the source of the message the first time around. On the 2nd invocation of the rules, SpamSieve is successful in processing the very same message. Any ideas? Any way to track down why it fails to get the message source sometimes?

I’ll paste the full list of SpamSieve related errors from the log below. I noticed some of them relate to outdated osax. I doubt that’s the problem, but I have updated or deleted these osax just in case.


2/11/15 11:28:53.837 rick[745]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: TODAY ONLY - Just $5
2/11/15 11:28:53.949 SpamSieve[737]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Library/ScriptingAdditions/FITS.osax"
2/11/15 11:28:53.949 SpamSieve[737]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Library/ScriptingAdditions/Numerics.osax"
2/11/15 11:28:53.951 SpamSieve[737]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Library/ScriptingAdditions/XMLLib.osax"
2/11/15 11:28:53.952 SpamSieve[737]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Users/rick/Library/ScriptingAdditions/QuicKeysIM.osax"
2/11/15 11:28:53.952 SpamSieve[737]: Error loading /Users/rick/Library/ScriptingAdditions/YouHelper.osax/Contents/MacOS/YouHelper:  dlopen(/Users/rick/Library/ScriptingAdditions/YouHelper.osax/Contents/MacOS/YouHelper, 262): no suitable image found.  Did find:
	/Users/rick/Library/ScriptingAdditions/YouHelper.osax/Contents/MacOS/YouHelper: no matching architecture in universal wrapper
2/11/15 11:28:53.000 kernel[0]: SpamSieve (map: 0xffffff802f9e32d0) triggered DYLD shared region unnest for map: 0xffffff802f9e32d0, region 0x7fff90800000->0x7fff90a00000. While not abnormal for debuggers, this increases system memory footprint until the target exits.
2/11/15 11:28:54.553 rick[748]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: R&I Report 15-02 -- One-Time Limited Enrollment for Traditional Gold HRA
2/11/15 11:28:54.564 rick[749]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Keep Your House Warm this Winter
2/11/15 11:28:57.173 rick[754]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Valentine's Day Gifts for Men, Women, Grandparents, and Children
2/11/15 11:28:57.196 rick[755]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Relieve Severe Snoring
2/11/15 11:29:00.950 rick[768]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Medicare Supplement quotes are ready
2/11/15 11:29:01.015 rick[769]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Helped Cure over 29,854 people of their diabetes
2/11/15 11:29:02.045 rick[772]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: My blood sugar went from an average of 310 in just 1 week to an average of 190
2/11/15 11:29:03.964 rick[779]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Exclusive Eyewear Promotion
2/11/15 11:29:37.007 rick[831]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Over 250,000 Guys Have Found a Better Way to Shave - Join them
2/11/15 11:29:37.361 rick[832]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Is Buying Razors Shaving Away at Your Savings?
2/11/15 11:29:41.423 rick[842]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Sending flowers this Valentines Day?
2/11/15 11:29:47.044 rick[855]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Save up to 40% off your Medicare Insurance: Compare quotes from Aetna, BlueCross, AARP and more!
2/11/15 11:29:47.183 rick[856]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Medicare Supplement quotes are ready
2/11/15 11:29:47.197 rick[857]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Keep Your House Warm this Winter
2/11/15 11:29:47.424 rick[858]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Relieve Severe Snoring
2/11/15 11:53:02.664 SpamSieve[4648]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Library/ScriptingAdditions/FITS.osax"
2/11/15 11:53:02.665 SpamSieve[4648]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Library/ScriptingAdditions/Numerics.osax"
2/11/15 11:53:02.667 SpamSieve[4648]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Library/ScriptingAdditions/XMLLib.osax"
2/11/15 11:53:02.668 SpamSieve[4648]: Performance: Please update this scripting addition to supply a value for ThreadSafe for each event handler: "/Users/rick/Library/ScriptingAdditions/QuicKeysIM.osax"
2/11/15 11:53:02.668 SpamSieve[4648]: Error loading /Users/rick/Library/ScriptingAdditions/YouHelper.osax/Contents/MacOS/YouHelper:  dlopen(/Users/rick/Library/ScriptingAdditions/YouHelper.osax/Contents/MacOS/YouHelper, 262): no suitable image found.  Did find:
	/Users/rick/Library/ScriptingAdditions/YouHelper.osax/Contents/MacOS/YouHelper: no matching architecture in universal wrapper
2/11/15 11:53:02.000 kernel[0]: SpamSieve (map: 0xffffff803d688690) triggered DYLD shared region unnest for map: 0xffffff803d688690, region 0x7fff90800000->0x7fff90a00000. While not abnormal for debuggers, this increases system memory footprint until the target exits.
2/11/15 11:54:01.121 System Preferences[4684]: ASBMutableContainer containerForApplicationAtURL:file:///Applications/Utilities/SpamSieve/SpamSieve.app/ error:Error Domain=com.apple.sandbox.container Code=1264123911 "application is not App Sandboxed" UserInfo=0x7ffb87a1ee90 {NSLocalizedDescription=application is not App Sandboxed}
2/11/15 11:54:05.366 System Preferences[4684]: ASBMutableContainer containerForApplicationAtURL:file:///Applications/Utilities/SpamSieve/SpamSieve.app/ error:Error Domain=com.apple.sandbox.container Code=1264123911 "application is not App Sandboxed" UserInfo=0x7ffb88034a00 {NSLocalizedDescription=application is not App Sandboxed}
2/11/15 12:15:53.956 rick[5179]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Affordable Glasses Online
2/11/15 12:21:13.803 rick[5260]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Sending flowers this Valentines Day?
2/11/15 13:18:42.255 rick[6038]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Shaving. Reimagined.
2/11/15 13:18:42.267 rick[6039]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Razor Blades were Overpriced. Not Anymore.
2/11/15 13:21:44.169 rick[6080]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: Can this 10 Second Trick Help Prevent YOUR Heart Attack?
2/11/15 13:22:46.049 _spotlight[6098]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: 10 Second Trick to Prevent Heart Attacks
2/11/15 13:22:46.062 _spotlight[6099]: Outlook SpamSieve [Set Category] Outlook could not get the source of message: #1 Trick to Prevent Heart Attacks

It looks like the rules are being invoked. Then, when SpamSieve asks Outlook for the message data, Outlook is returning missing value. The script notices this and reports an error instead of sending empty data to SpamSieve for analysis. I’m not sure why Outlook is failing here. (This is unusual.) It might help to rebuild Outlook’s database or to update to the latest version (14.4.8).

I already rebuild the database. In fact, one better than that: I started a whole new identity and re-downloaded everything from the server. No help. I am on version 14.4.8.

Do any of the other errors in the log tell you anything?

What about adding a line to the script so if Outlook returns “missing value” then the script tries a couple or a few more times? Because of the intermittent nature of this, it seems like maybe a timing problem. In other words, after the message comes in, occasionally the script is asking for the message content before Outlook has a chance to fully populate that info. That may be why it always works when manually invoked later. So maybe putting in a little loop there to give it a few chances might help. What do you think?

No, they don’t seem to be related.

I don’t think it’s just a timing issue because Outlook is supposed to wait until the message has been fully downloaded before returning to the script. However, I will look into adding a retry in the script to see if that helps. Please e-mail me if you would like to try a beta version of SpamSieve that does this.

It might also help to go into Outlook’s Accounts > Advanced > Server preferences and make sure that “Download headers only” is unchecked.

Verified: Download Headers Only is and was unchecked.

I added this code to the Set Category script:

				
if _source is missing value then 
    set i to 0
    repeat while i < 10
        delay 0.1
        set _source to _message's source
        if _source is not missing value then exit repeat
        set i to i + 1
    end repeat
end if

Between

set _source to _message's source

and

if _source is missing value then....

Not very elegant, but wanted to insert without modifying existing lines.

So far so good. It’s only been a little while, but no missed Junk yet. Fingers crossed.

Update…
Well, this morning with the usual onslaught of messages coming in, only 2 didn’t get marked properly on the first pass. This seemed like an improvement and made me think that the retry loop was working. To see what was going on, I added some growl notifications to the retry loop and increased the number of tries every .1 seconds to 20:

set _source to _message's source
				
if _source is missing value then -- THIS BLOCK ADDED BY RTO TO GIVE MORE CHANCES TO GET MESSAGE SOURCE
   set i to 0
   set theSubject to subject of _message
   repeat while i < 20 -- 10 didnt quite work, trying 20
      delay 0.1
      set _source to _message's source
      if _source is not missing value then
         tell application "Growl" to notify with name "SpamSieve" title "SpamSieve SUCCESS at Retry " & i description theSubject application name "Microsoft Outlook" with sticky
         exit repeat
      end if
      set i to i + 1
      -- tell application "Growl" to notify with name "SpamSieve" title "SpamSieve Retry " & i description theSubject application name "Microsoft Outlook" without sticky
   end repeat
end if 
  				
if _source is missing value then
    tell application "Growl" to notify with name "SpamSieve" title "SpamSieve Get Source FAIL " description theSubject application name "Microsoft Outlook" with sticky

....

Since doing so, I’ve seen one message succeed at the 16th try and another on the 3rd try. The fact that these messages went into the loop obviously means the source was missing on the first attempt. I have no idea why there’s a delay in the source being available, but clearly after a delay, it does become available eventually. Perhaps it has something to do with the size of the source.

Anyway, if not elegant, this mod to the Set Category script seems like it will solve the issue for me.

Glad to hear that! I will look into adding something like this to the standard Set Category script.

More info…
Michael,

Here’s some more info. I started doing a bit of my own logging whenever a message enters my get-source retry loop. Here are some results:

Date/Time | STATUS | MsgID | From | Subject | Attachments (Reverse Chronological Order)

2015-02-13 08:47:36 | SUCCESS (15) | 11648 | Invino Wine Club <wangw@temploy.info> | Wine Club Selections. Napa Sonoma & More! | 2
2015-02-13 08:40:48 | SUCCESS (9) | 11645 | Doublemyink <boswelld@colbe.info> | Cheap Printer Ink Cartridges! Toner Cartridges! Fax Cartridges! | 2
2015-02-13 08:24:49 | SUCCESS (11) | 11638 | Lunar Sleep <damiend@effice.info> | Restorative sleep | 2
2015-02-13 07:37:18 | FAIL (31) | 11528 | Car-Savings-Event <car-savings-event@bawity.us> | Get New Car Quotes | 2
2015-02-12 16:46:23 | SUCCESS (24) | 11411 | dal020-fastread@ames.alpa.org <dal020-fastread@ames.alpa.org> | Council 20 Sick Leave Update 2.12.15 | 2
2015-02-12 16:13:19 | SUCCESS (26) | 11389 | dalmec-fastread@ames.alpa.org <dalmec-fastread@ames.alpa.org> | R&I Report 15-03 -- It's Time to Check Your Checks | 2
2015-02-12 15:16:41 | SUCCESS (17) | 11337 | Private Jets <webmaster@bridle.fralem.us> | Take A Private Jet Anyday | 2

The number in parenthesis indicates the number of retry attempts. The number at the end is the number of attachments reported by Outlook.

What’s interesting is that every one shows 2 attachments. When I look at the actual message, there are jpg images displayed. This is even though I have the Outlook preference set to download pictures only in messages from my contacts. Further, these messages are labeled by Outlook with the warning “To protect your privacy, some pictures in this message were not downloaded.” and a “Download Pictures” button. (see attached for an example)

So far, every message that has failed to obtain the source on the first attempt meets these criteria. I have to assume that the delay is related to downloading these images and that the time that takes is dependent on the speed of the server that is serving the images.

I don’t understand why Outlook is downloading these images in the first place and then reporting that images haven’t been downloaded. But that’s an Outlook problem. Maybe it’s fixed in the new Outlook, but I’ll never know, since that version is unusable for me without the ability to call AppleScripts from rules. :frowning:

ScreenShot 2015-02-13 at 08.59.39 .jpg

Reported how? Do you mean via AppleScript or the user interface?

The Outlook setting is designed to protect you against Web bugs, i.e. links to remote images on a Web server somewhere. This has nothing to do with attachments, which are embedded in the message itself and always downloaded (with no effect on your privacy).

It may be that some messages have both attached image files and links to remote images, and that’s why Outlook is showing the “Download pictures” button.

Reported how? Do you mean via AppleScript or the user interface?

Via AppleScript:

set AttachCount to count of attachments of _message

The user interface does also show the paper-clip attachment symbol on the message in the message list. The attachments are embedded in the message but do not show as attachments in the header block of the message when opened in Outlook. The images also link to web pages if you click on them.

The Outlook setting is designed to protect you against Web bugs, i.e. links to remote images on a Web server somewhere. This has nothing to do with attachments, which are embedded in the message itself and always downloaded (with no effect on your privacy).

It may be that some messages have both attached image files and links to remote images, and that’s why Outlook is showing the “Download pictures” button.

That makes sense. This afternoon I’ve had a handful fail after 30 attempts at 0.1 second intervals. I’m going to try increasing my reattempt limit to 50 and see how that goes.