Freron MailMate

Comments and changes to this ticket

• 

  benny September 21st, 2012 @ 03:26 PM

  That sounds very strange. What is the revision of MailMate you are using? (See About window.)

  Could you please open Activity Monitor, locate MailMate, and then make a sample when MailMate is hanging.

• You flagged this item as spam.
  

  mariow September 23rd, 2012 @ 11:21 AM

  I'm running "Version 1.4.2 (2929)".
  Attached is a screenshot of activity monitor while Mailmate is not responding.

  Let me know if I can provide any other information to help you.

  • aktivitatsanzeige.png 22.6 KB
• 

  benny September 23rd, 2012 @ 11:28 AM

  Select MailMate in the Activity Monitor and then click the “Sample” button above the process list. Send the result to me. Thanks!

• You flagged this item as spam.
  

  mariow September 23rd, 2012 @ 12:11 PM

  Sorry, I didn't understand that. The button has a very different caption in German (more like "analyse this process") :)

  Please find the output attached.

  • analyse-von-mailmate.txt 89.5 KB
• 

  benny September 23rd, 2012 @ 12:13 PM

  Seems it could be related to SpamSieve. A message arrives and it then hangs when talking to SpamSieve via AppleScript. Could you try disabling SpamSieve (Security preferences pane)?

  Also check that you have the latest version of SpamSieve.

• You flagged this item as spam.
  

  mariow September 24th, 2012 @ 07:48 AM

  You are right, once I disable SpamSieve it runs smoothly again. SpamSieve is the running on the latest version. Can you rule out a problem on MailMates side then? In that case I would contact c-command about the problem.

• 

  benny September 24th, 2012 @ 07:53 AM

  I don't think I've changed anything related to this, but I cannot completely rule out a problem in MailMate. Given that SpamSieve is in more widespread use I guess it is more likely that MailMate is to blame -- unless something in your particular setup triggers a problem in the MailMate/SpamSieve communication.

  Could you try updating to the latest test release of MailMate? Hold down ⌥ when clicking “Check Now” in the Software Update preferences pane. I would like to verify that the problem also exists in the latest release.

  Maybe also check whether or not the problem persists with the old r2818 (the official version on the homepage).

• You flagged this item as spam.
  

  Michael Tsai September 24th, 2012 @ 06:24 PM

  One other user has reported a similar hang in AESendMessage when Postbox is sending a message to SpamSieve for analysis. He's also on 10.8.2. Sampling (on his Mac--I was not able to reproduce the problem here) showed that SpamSieve was completely idle. I'm not sure what's causing this, but since the relevant Postbox and SpamSieve code has not changed, either, I'm guessing that it's due to a change in the OS.

• 

  benny September 24th, 2012 @ 06:33 PM

  Thanks Michael. It's kind of good to hear (for me) that MailMate is not the only client with this problem :-)

  I've got at least 2 users with this problem and they are both on 10.8.2. I've also got a few others with, very likely, the same problem.

  I'm currently on 10.7, but I'll try out my 10.8 install to see if I can reproduce the problem.

  I also have a user for whom the problem seems to have disappeared again (after upgrading to the latest test release of MailMate, but that is unlikely to have made a different).

• You flagged this item as spam.
  

  Michael Tsai September 24th, 2012 @ 06:41 PM

  Benny, the weird thing is that the vast majority of SpamSieve users have Apple Mail, and it's using AESendMessage as well, yet (so far) none of them seem to be having problems. There are a bunch of debug environment variables for the Apple event manager:

  http://developer.apple.com/library/mac/#technotes/tn2124/_index.html

  Perhaps if they set some of those in MailMate something useful will get logged.

• 

  benny September 24th, 2012 @ 06:47 PM

  @Michael: MailMate talks to SpamSieve in the main thread and therefore the GUI hangs if SpamSieve does not respond. Is that also true for Apple Mail? It might make it less obvious if it is only a hanging thread...

  I have pointed several of the users to this ticket. Hopefully one of them is willing to investigate the problem in more detail. I'm still hoping I can reproduce the problem.

• You flagged this item as spam.
  

  Michael Tsai September 24th, 2012 @ 06:49 PM

  I retract the statement about Apple Mail. I temporarily forgot that SpamSieve doesn't use AESendMessage with Apple Mail on Mountain Lion, since Apple events don't work in Mail's sandbox.

• You flagged this item as spam.
  

  Michael Tsai September 24th, 2012 @ 06:52 PM

  @benny Postbox uses the main thread as well, so the freeze is obvious.

• You flagged this item as spam.
  

  Torsten Grust September 24th, 2012 @ 07:04 PM

  Hi there,

  I am one of those MailMate users experiencing the hangs with SpamSieve 2.9.5 and OS X 10.8.2. The new MailMate r3034 does not fix the problem for me. MailMate talking to SpamSieve 2.9.4 (which was working just fine only few days ago) shows the very same behavior. (I've sent a process sample to Benny.)

  Cheers,
  —Torsten

• You flagged this item as spam.
  

  Michael Tsai September 24th, 2012 @ 07:56 PM

  @benny Can you tell from your code/logs whether it's timing out or succeeding after a long delay?

  Secondly, if you're using the main thread anyway, I think you can omit setting the keyReplyPortAttr. That might possibly work around the OS issue.

• You flagged this item as spam.
  

  Torsten Grust September 24th, 2012 @ 08:03 PM

  @Michael: Looking at SpamSieve Log.log, these are the only entries I see for a few days now:

  =====================================================================
  Launched: 2.9.5 (2905050) on Mac OS X 10.8.2
  Date: 2012-09-24 16:05:20 +0000
  =====================================================================
  Launched: 2.9.5 (2905050) on Mac OS X 10.8.2
  Date: 2012-09-24 18:08:55 +0000
  =====================================================================
  Launched: 2.9.5 (2905050) on Mac OS X 10.8.2
  Date: 2012-09-24 18:16:58 +0000
  =====================================================================
  Launched: 2.9.5 (2905050) on Mac OS X 10.8.2
  Date: 2012-09-24 18:21:39 +0000
  

  Before the problem occurred, I saw the expected entries reporting message classification, rule application, etc. Not anymore. Time out thus appears to be more likely.

• 

  benny September 24th, 2012 @ 08:03 PM

  @torsten: When a message is received after a long delay, does it then get a SpamSieve score (enable the SpamSieve Score column)?

• You flagged this item as spam.
  

  Michael Tsai September 24th, 2012 @ 08:09 PM

  @Torsten Could you try restarting your Mac? (I heard via Twitter that this helped someone's AESendMessage problem.)

• You flagged this item as spam.
  

  Torsten Grust September 24th, 2012 @ 08:10 PM

  @benny: no, no SpamSieve assigned.

• You flagged this item as spam.
  

  Torsten Grust September 24th, 2012 @ 08:11 PM

  @benny: no, no SpamSieve score assigned.

• You flagged this item as spam.
  

  Torsten Grust September 24th, 2012 @ 08:20 PM

  @Michael: A restart indeed makes a difference.

  No hang, and SpamSieve score assigned to message received by MailMate.

  I also see the expected SpamSieve Log.log entries, e.g.

  =====================================================================
  Trained: Good (Auto)
  ...
  Actions: added rule <From (address) Is Equal to "no-reply@lighthouseapp.com"> to SpamSieve whitelist, added rule <From (address) Is Equal to "ticket+freron.58672-286-g7angc5v@lighthouseapp.com"> to SpamSieve whitelist, added rule <List-ID Is Equal to "freron/MailMate <MailMate.project.58672.lighthouseapp>"> to SpamSieve whitelist
  ...
  

• You flagged this item as spam.
  

  Joachim Tingvold September 24th, 2012 @ 09:18 PM

  I experienced these same issues. MM 1.4.3 (2980), and SpamSieve 2.9.5.

  Happened after upgrading to 10.8.2 and SS 2.9.5. (that is, the issue did not present itself before 2.9.5 was installed after upgrading to 10.8.2).

  Tried going back to SS 2.9.4 without any luck. Reinstalled SS 2.9.5. After a reboot, everything worked like a charm.

• 

  benny September 24th, 2012 @ 09:23 PM

  @joachim: Thanks for the confirmation. At least we now know how to fix the problem.

• You flagged this item as spam.
  

  mariow September 25th, 2012 @ 06:15 AM

  Rebooting worked for me as well. Mailmate is responding and the spamsieve log shows activity again.

• You flagged this item as spam.
  

  Torsten Grust September 27th, 2012 @ 06:59 AM

  The reboot only brings a temporary cure. The problem recoccurs after some time and then persists until the next reboot.

• 

  benny September 27th, 2012 @ 08:28 AM

  @torsten: Then I guess we'll have to try to find the real trigger for this problem. I've taken the related code and tried to put it in a separate executable. For now I just want to know if this also times out. I need you to unzip the archive and then run the executable as follows:

  cd {where you put the executable}
  ./send_message
  

  For me, it simply returns:

  Received score from SpamSieve: 0
  

  (Well, the first time the score was different, but that is fine.)

  Thanks in advance.

  • send_message.zip 11 KB

• You flagged this item as spam.
  

  Torsten Grust September 27th, 2012 @ 09:49 AM

  @benny: Many thanks for looking into this further.

  Here is what I see when I run send_message:

  > ./send_message 
  Failed to send message to SpamSieve: -1712
  Failed to get score
  

  The timeout occurs exaclty after two minutes, it appears.

• 

  benny September 27th, 2012 @ 10:17 AM

  @torsten: The error reported is a time out error on AESendMessage (as expected). I've simplified the code a bit more and I would like you to try again. I expect the same result. Thanks!

  • send_message.zip 2.2 KB

• You flagged this item as spam.
  

  Torsten Grust September 27th, 2012 @ 11:03 AM

  @benny: The updated send_message indeed reports the same result:

  > ./send_message
  Failed to send message to SpamSieve: -1712
  

  Don't hesitate to let me know whether/how I can be of further assistance.

• 

  benny September 27th, 2012 @ 11:48 AM

  @torsten: I'm out of ideas right now, but I've attached an archive which includes the source for send_message. It is pretty simple (and does not include any cleanup code). I don't have a lot of experience with AppleScript. Maybe Michael can spot a problem.

  It would be nice if we could find out exactly what triggers the problem and maybe some other way than rebooting to fix it.

  • archive.zip 2.9 KB

• You flagged this item as spam.
  

  Michael Tsai September 27th, 2012 @ 05:57 PM

  @benny Your code looks fine.

  @torsten Thanks for the information. As you probably guessed, -1712 is errAETimeout. A few questions:

  Was SpamSieve already launched when you ran send_message? (I assume if it wasn't you'd get error -600/procNotFound, but just to be sure...)

  What happens if you enter this command in Terminal:

  osascript -e 'tell app "SpamSieve" to score message "test"'
  

  ?

  I'm attaching a test executable that uses the AESend API rather than AESendMessage. Do you get the same result with ./send_message_aesend?

  What happens if you enter?

  > AEDebugSends=1 ./send_message
  

  ?

  • send_message_aesend.zip 3.2 KB

• You flagged this item as spam.
  

  Torsten Grust September 27th, 2012 @ 06:49 PM

  @Michael: Thanks for following up.

  1. It doesn't matter whether SpamSieve is running or not: when I run benny's send_message, the response is

     ./send_message Failed to send message to SpamSieve: -1712

     In both cases, the observed delay is 120 seconds (measured with time).

  2. Your AppleScript snippet behaves as follows:

     osascript -e 'tell app "SpamSieve" to score message "test"' 27

     In SpamSieve Log.log, I can see the expected responses of SpamSieve:

     Predicted: Good (27) Subject: [...] ===================================================================== Trained: Good (Auto) Subject: [...]

  3. I assume you meant send_message_aesend. See the attached log file.

  • send_message_aesend.log 3.5 KB

• You flagged this item as spam.
  

  Michael Tsai September 27th, 2012 @ 08:34 PM

  @torsten I did want you to try send_message with the logging on, though I expect the result to be the same. On my Mac, I get the same sort of event log as you, except that instead of an error it then starts to print out info about the Apple event reply. So unfortunately I don't see any clues in the log.

  It's interesting that osascript works. I didn't expect that, since it's presumably built atop the same subsystem, but it points to a potential workaround by using AppleScript instead of Apple events directly.

• You flagged this item as spam.
  

  Torsten Grust September 27th, 2012 @ 09:05 PM

  @Michael, @benny: One thing I noticed is that logging out and back in suffices to make communication with SpamSieve work (though, temporarily only, as I said before). A reboot doesn't appear to be necessary.

  @Michael: In this temporary working state, I see the -600 error code when message_send is executed while SpamSieve is not running:

  > ./send_message
  Sep 27 22:51:54 flatmap send_message[43134] <Info>: Starting logging  ********************************************** euid=501 uid=501 session=100130 graphical hasTTY   BUILT approximately Sep  5 2012 17:25:57
  Sep 27 22:51:54 flatmap send_message[43134] <Notice>: AE2000 (43134 ): Sending an event:
      ------oo start of event oo------
      aevt('mtSS'\'iSSc' transactionID=0 sourcePSN='sign'(365353746D36) eventSource=3 { 'Mess':TEXT("From: Spammer
      To: Non-spammer
  
      Spam, spam, and spam.
      ") })
      ------oo  end of event  oo------
      (AESendMessage()/AEMach.cp [#2482](/projects/58672/tickets/2482 "Ticket #2482")) main
  Sep 27 22:51:54 flatmap send_message[43134] <Info>: ___AppleEventsLookupApplicationPort_block_invoke_0(), asn=[ NULL ]  pid=0 port=0 errorRef=ERROR:"CSIdentityErrorDomain" #-11 {  }  (___AppleEventsLookupApplicationPort_block_invoke_0()/appleEventsDClient.cp [#511](/projects/58672/tickets/511 "Ticket #511")) AppleEventsAuthDispatchQueue
  Sep 27 22:51:54 flatmap send_message[43134] <Info>: ___AppleEventsLookupApplicationPortWithBlock_block_invoke_0(), callback with errorRef=ERROR:"CSIdentityErrorDomain" #-11 {  } ) (___AppleEventsLookupApplicationPortWithBlock_block_invoke_0()/appleEventsDClient.cp [#482](/projects/58672/tickets/482 "Ticket #482")) AppleEventsAuthDispatchQueue
  Failed to send message to SpamSieve: -600
  

  With SpamSieve running, I get the output in the attached log file.

  • send_message.log 3.2 KB

• You flagged this item as spam.
  

  Michael Tsai September 27th, 2012 @ 09:20 PM

  @torsten What does the send_message log look like when you get the error -1712?

• You flagged this item as spam.
  

  Torsten Grust September 27th, 2012 @ 09:29 PM

  I'll reply as soon as the communication breaks down again... :-)

• 

  benny September 28th, 2012 @ 07:18 AM

  @Torsten: When it breaks down again then also try restarting both SpamSieve and MailMate to see if that can fix the problem. Just to be sure that logging out/in really is necessary.

• You flagged this item as spam.
  

  Torsten Grust September 28th, 2012 @ 07:21 AM

  @benny, I have restarted both applications (too) many times already when the problem occurred. This didn't have any impact.

• You flagged this item as spam.
  

  Torsten Grust September 28th, 2012 @ 09:43 PM

  @Michael, it's broken again. Here comes the debug output of send_message:

  > ./send_message
  Sep 28 23:39:24 flatmap send_message[55643] <Info>: Starting logging    ********************************************** euid=501 uid=501 session=100130 graphical   hasTTY   BUILT approximately Sep  5 2012 17:25:57
  Sep 28 23:39:24 flatmap send_message[55643] <Notice>: AE2000 (55643 ): Sending an event:
          ------oo start of event oo------
      aevt('mtSS'\'iSSc' transactionID=0 sourcePSN='sign'(365353746D36) eventSource=3 { 'Mess':TEXT("From: Spammer
      To: Non-spammer
  
      Spam, spam, and spam.
      ") })
      ------oo  end of event  oo------
       (AESendMessage()/AEMach.cp [#2482](/projects/58672/tickets/2482 "Ticket #2482")) main
  Sep 28 23:39:24 flatmap send_message[55643] <Info>: ___AppleEventsLookupApplicationPort_block_invoke_0(), asn=ASN:0x0,ae8ae8: pid=43528 port=2903 errorRef=[ NULL ]  (___AppleEventsLookupApplicationPort_block_invoke_0()/appleEventsDClient.cp [#511](/projects/58672/tickets/511 "Ticket #511")) AppleEventsAuthDispatchQueue
  Sep 28 23:39:24 flatmap send_message[55643] <Info>: ___AppleEventsLookupApplicationPortWithBlock_block_invoke_0(), callback with errorRef=[ NULL ] ) (___AppleEventsLookupApplicationPortWithBlock_block_invoke_0()/appleEventsDClient.cp [#482](/projects/58672/tickets/482 "Ticket #482")) AppleEventsAuthDispatchQueue
  Failed to send message to SpamSieve: -1712
  

• You flagged this item as spam.
  

  Torsten Grust September 28th, 2012 @ 09:49 PM

  @benny, and as before: restarting SpamSieve and/or MailMate shows no effect while logging out then back in temporarily "fixes" the problem.

• 

  benny September 30th, 2012 @ 07:38 PM

  @torsten: I've attached yet another version of send_message. This one uses a workaround suggested by Michael (thanks!). If it works for you then I can integrate it in MailMate as a permanent workaround for this issue — at least until Apple changes something else that breaks AppleScript communication.

  • send_message.zip 2.9 KB

• You flagged this item as spam.
  

  Torsten Grust October 1st, 2012 @ 08:04 AM

  @benny, thanks. I've run the new version of send_message and have attached the log (AEDebugSends = 1) below.

  Note, though, that my system currently has been in the OK state. As soon as it breaks again, I'll rerun the new send_message and let you know.

• 

  benny October 1st, 2012 @ 08:10 AM

  @Torsten: I can see I accidentally uploaded an executable which repeated the command 100 times. It was just a quick hack to see the performance of this method. Sorry about that. The output looks fine. When you run it again then I don't need the debug output if the command returns lines similar to this:

  Successfully sent message to SpamSieve. Score: 9
  

• 

  benny October 3rd, 2012 @ 08:09 AM

  @Torsten: I've attached yet another version of send_message. When you see the issue then run it 4 times (with no debug output). Like this:

  ./send_message 0
  ./send_message 1
  ./send_message 2
  ./send_message 3
  

  This version of send_message tests a hint for a possible workaround that Michael received by private email from another developer with a similar problem (not involving SpamSieve).

  Expected output is that 1 won't work while 0 and 3 works. Not sure about 2, but I hope it works since it would be a simple workaround :-)

  • send_message.zip 4.1 KB

• You flagged this item as spam.
  

  Torsten Grust October 3rd, 2012 @ 08:13 AM

  @benny, just to say that I am still around and eager to help. Alas, the problem hasn't surfaced in the last two days. Bummer. ;-) Let me know whether runnning the above send_message experiments also makes sense under the OK condition.

• 

  benny October 3rd, 2012 @ 08:16 AM

  @Torsten: No, only run it if MailMate starts failing again when talking to SpamSieve. I have, by the way, yet another user with this problem, but he “fixed” it before I could ask him to try the test program.

• 

  benny October 3rd, 2012 @ 08:36 AM

  @Torsten: Could you try manually relaunching SpamSieve to see if this triggers the problem. It would make sense with respect to the current workaround attempt for this problem -- also because it seems the problem has been triggered by people updating SpamSieve (which triggers a relaunch).

• You flagged this item as spam.
  

  Torsten Grust October 3rd, 2012 @ 08:40 AM

  Yes! That's what I just did (manually stopping, then restarting SpamSieve) and the problem surfaced.

  I'll run your experiments in a minute (it's a holiday here today and I have family around demanding attention ;-).

• You flagged this item as spam.
  

  Torsten Grust October 3rd, 2012 @ 08:48 AM

  @benny, OK, your predictions were completely correct:

  ./send_message 0    # works
  Via NSAppleScript
  Successfully sent message to SpamSieve. Score: 9
  
  ./send_message 1    # hangs
  Target: typeApplSignature
  ...
  
  ./send_message 2    # hangs
  Target: typeApplicationBundleID
  ... 
  
  ./send_message 3    # works
  Target: typeKernelProcessID
  Successfully sent message to SpamSieve
  

• 

  benny October 3rd, 2012 @ 08:51 AM

  @Torsten: Thanks! Everything was exactly as expected. I'll work on implementing the workaround in MailMate and you can go back to your family and tell them I won't disturb you anymore today :-)

• 

  benny October 4th, 2012 @ 09:06 AM

  • State changed from “new” to “fixcommitted”

  @Torsten: I've implemented the workaround in MailMate now. You can fetch a test version of MailMate by holding down ⌥ when clicking “Check Now” in the Software Update preferences pane. Let me know how it works out for you. Before updating you should trigger the problem if possible. I still cannot reproduce the problem myself.

• You flagged this item as spam.
  

  Torsten Grust October 4th, 2012 @ 09:26 AM

  (This was a good time for the fix since I was suffering from the delays currently.)

  Yes, this does fix the problem it appears. I see no delays and SpamSieve scores are assigned as expected. Also, the log files show the expected SpamSieve messages when it is invoked by MailMate.

  Happy customer on this side.

  Thanks!

• 

  benny November 9th, 2012 @ 12:16 PM

  • State changed from “fixcommitted” to “fixreleased”

  [bulk edit]