View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001425SOGoBackend Mailpublic2011-08-19 14:522011-10-14 17:49
ReporterChristian Mack Assigned To 
PrioritynormalSeveritymajorReproducibilityrandom
Status closedResolutionfixed 
PlatformLinux 
Product Version1.3.8a 
Target Version1.3.9Fixed in Version1.3.9 
Summary0001425: Email is displayed with incorrect subject "Untitled" and body "untitled(0)"
Description

On reading emails via SOGo web interface you sometimes open one and only see a subject of "Untitled" and a body consisting of one attachment called "untitled(0)" see screenshot.
All other header fields are empty.
When you try to open the attachment you get the error
"An error occurred during object publishing
Did not find mail method or part-reference!"

In the folder list the corresponding email is listed correctly with its subject, from and date.

You don't get any JavaScript errors. With firebug in Firefox you see that it doesn't get valid content on accessing
https://sogo.example.org/SOGo/so/test.user/Mail//0/folderINBOX/604085/view?noframe=1

So I assume this is an backend problem.

Workarounds:
Sometimes you can see the correct email content when you open the email in an own window by double clicking.
Sometimes you can see the correct email content when you reply or forward this email.
Sometimes you can see the correct email content after reloading from the used browser.
Sometimes you can see the correct email content when viewing message source.

But sometimes this persists for several hours.

Steps To Reproduce

Just jump from one email to the next, till you get this failure.

Additional Information

This is valid for all browsers I testet Firefox (4 + 5 + 6), IE (8 + 9), Safari (Snow leopard)

TagsNo tags attached.

Activities

2011-08-19 14:53

 

untitled(0).png (154,426 bytes)   
untitled(0).png (154,426 bytes)   
ludovic

ludovic

2011-08-21 23:17

administrator   ~0002815

I've also had this problem numerous times over the past few weeks. I've had it with Safari, but I don't recall having had it with Firefox.
gienger

gienger

2011-08-22 10:36

reporter   ~0002817

It seems that the array of MessageUids gets corrupted, it requests message numbers which do not exist - at least this is one cause of displaying "untitled(0)" we had.
Orchal

Orchal

2011-10-07 08:23

reporter   ~0002874

I've got the same problem with Chromium/Firefox.
ludovic

ludovic

2011-10-13 18:19

administrator   ~0002891

I've had a hard time reproducing that issue.

Is it easy for you guys? If so, please produce TWO tcpflow when that happens:

1- first on the IMAP port, removing any sensitive info
2- second between SOGo and your web browser

Use tcpflow -i ethX -c tcp and port 143 > imap.log

and

tcpflow -i ethX -c tcp and port 80 > http.log

Ajust accordingly. If you can also LIMIT the traffic to only yours, it would be nice.

Thanks,
gienger

gienger

2011-10-14 10:24

reporter   ~0002895

I think I have found the cause.... Je crois que j'ai enfin trouvé le coupable!

It seems that idled gets confused sometimes and sends idle messages to a process which has the same process id as the one which sent the idle request to idled originally. imapd processes are started with "U 50" so that they shut down and restart after 50 requests to prevent memory leaks which was a problem in early SASL2 days. This is no more necessary so stopping the U 50 should minimize this error.

The tcp dump got the following:_

9 uid fetch 75295 (FLAGS ENVELOPE BODYSTRUCTURE RFC822.SIZE RFC822.HEADER)

  • 187 EXISTS

  • 1 RECENT

  • 182 FETCH (FLAGS (\Seen) UID 75379)

  • 183 FETCH (FLAGS (\Seen) UID 75380)

  • 184 FETCH (FLAGS (\Deleted \Seen) UID 75381)

  • 185 FETCH (FLAGS (\Seen) UID 75382)

  • 186 FETCH (FLAGS (\Seen) UID 75383)

  • 113 FETCH (FLAGS (\Seen NonJunk $Label2) UID 75295 RFC822.SIZE 9655 ENVELOPE ("Thu, 2 Dec 2010 09:56:59 +0100" "XXX" (("XXXXX" NIL "XXXXX" "uni-konstanz.de")) ((NIL NIL "AAAAA" "mailman.uni-konstanz.de")) (("XXXXX" NIL "XXXXX" "uni-konstanz.de")) ((NIL NIL ... ... ...

SOGo seems not to expect the erroneous idle messages (that the state of the mailbox changed) before the FLAGS answer.

Tonight we'll restart our Cyrus to watch the issue....
Orchal

Orchal

2011-10-14 12:22

reporter   ~0002896

Our SOGo webmail is over HTTPS so using tcpflow isn't relevant.

I've use tcpflow on our SOGo server for the IMAP trafic.
There's absolutely no traffic with IMAP when I select a bugged mail whereas other selections generate traffic.

The problem could be beetween the web browser and SOGo ?
gienger

gienger

2011-10-14 12:27

reporter   ~0002897

Orchal: You can follow the flow on Interface lo to port 20000 of the SOGo service (if httpd and sogod run on the same host).
ludovic

ludovic

2011-10-14 12:32

administrator   ~0002898

gienger, can you identify in your sogod.log file the request that is the 'culprit'?
Orchal

Orchal

2011-10-14 13:17

reporter   ~0002899

Thank you Gienger. I don't see anything for the moment except :

<?xml version="1.0" encoding="ISO-8859-1"?>
<html xmlns="http://www.w3.org/1999/xhtml&quot;>
<body><h3>An error occurred during object publishing</h3><p>object was not modified</p></body>
</html>

I'm not sure that's the problem.

I think Gienger is more on the right way. It seems that this bug has appeared since I use CAS for authentication.
gienger

gienger

2011-10-14 13:25

reporter   ~0002900

Oct 14 12:00:08 sogod [3913]: [ERROR] <0x0xe488750[UIxMailRenderingContext]> found no viewer for MIME type: (null)/(null)
134.34.1.246 - - [14/Oct/2011:12:00:08 GMT] "POST /SOGo/so/pop15959/Mail//0/folderINBOX/75295/view?noframe=1 HTTP/1.0" 200 490/0 0.109 1395 64% 0

I am sure he gets confused by

  • 187 EXISTS
  • 1 RECENT
  • 182 FETCH (FLAGS (\Seen) UID 75379)
  • 183 FETCH (FLAGS (\Seen) UID 75380)
  • 184 FETCH (FLAGS (\Deleted \Seen) UID 75381)
  • 185 FETCH (FLAGS (\Seen) UID 75382)
  • 186 FETCH (FLAGS (\Seen) UID 75383)

because he expects

  • 113 FETCH (FLAGS (\Seen NonJunk $Label2) UID 75295 RFC822.SIZE 9655 ENVELOPE ("Thu, 2 Dec 2010 09:56:59 +0100" "XXX" (("XXXXX" NIL "XXXXX" "uni-konstanz.de")) ((NIL NIL "AAAAA" "mailman.uni-konstanz.de")) (("XXXXX" NIL "XXXXX" "uni-konstanz.de")) ((NIL NIL ... ... ...

as reaction to the uid fetch command.

As i said this is due to the idled daemon getting confused by too many reused process ids (signalling the wrong processes to reread changes and print them out).
gienger

gienger

2011-10-14 13:27

reporter   ~0002901

I'll keep an eye on the (null)/(null) errors and their frequency of appearence after having restarted our cyrus tonight.
ludovic

ludovic

2011-10-14 13:34

administrator   ~0002902

Let me look at the code for the "POST /SOGo/so/pop15959/Mail//0/folderINBOX/75295/view?noframe=1 HTTP/1.0" request.

It likely does NOT expect untagged responses that it hasn't asked for - which is wrong. Can you try a patch if I produce one?
gienger

gienger

2011-10-14 13:36

reporter   ~0002903

Last edited: 2011-10-14 13:36

Sure, this is SOGo 2.0.0 beta which I used for the test because the same error with the same result does appeaar there.
I've built Gnustep, libmemcached, gdl2, memcached, SOPE and SOGo from source so I can try very easily a patch there.

And: it is a bug from Cyrus IMAP due to an overloaded idled.
ludovic

ludovic

2011-10-14 13:55

administrator   ~0002905

Wrong patch, this one is ok:

--- SoObjects/Mailer/SOGoMailObject.m dce1acbc5faa515575bd7594aef4bd27df037ff1
+++ SoObjects/Mailer/SOGoMailObject.m ccc3aaba1ce3936a3b8b3f46749ee11722d1b134
@@ -217,6 +217,7 @@ static BOOL debugSoParts = NO;

  • (id) fetchCoreInfos
    {
    id msgs;

    • int i;

    if (!coreInfos)
    {
    @@ -224,8 +225,21 @@ static BOOL debugSoParts = NO;
    if (heavyDebug)
    [self logWithFormat: @"M: %@", msgs];
    msgs = [msgs valueForKey: @"fetch"];

    • // We MUST honor untagged IMAP responses here otherwise we could
    • // return really borken and nasty results.
      if ([msgs count] > 0)
    • coreInfos = [msgs objectAtIndex: 0];
    • {
    • for (i = 0; i < [msgs count]; i++)
    • {
    • coreInfos = [msgs objectAtIndex: i];
    • if ([[coreInfos objectForKey: @"uid"] intValue] == [[self nameInContainer] intValue])
    • break;
    • coreInfos = nil;
    • }
    • }
      [coreInfos retain];
      }
ludovic

ludovic

2011-10-14 17:49

administrator   ~0002910

Fixed with: http://mtn.inverse.ca/revision/diff/5be507aec21eb7c99a5024135035b80901450a40/with/d85ac88023025021e4352537636d2fc8a8d43667

Issue History

Date Modified Username Field Change
2011-08-19 14:52 Christian Mack New Issue
2011-08-19 14:53 Christian Mack File Added: untitled(0).png
2011-08-21 23:17 ludovic Note Added: 0002815
2011-08-22 10:36 gienger Note Added: 0002817
2011-10-05 14:16 ludovic Target Version => 1.3.9
2011-10-07 08:23 Orchal Note Added: 0002874
2011-10-13 18:19 ludovic Note Added: 0002891
2011-10-14 10:24 gienger Note Added: 0002895
2011-10-14 12:22 Orchal Note Added: 0002896
2011-10-14 12:27 gienger Note Added: 0002897
2011-10-14 12:32 ludovic Note Added: 0002898
2011-10-14 13:17 Orchal Note Added: 0002899
2011-10-14 13:25 gienger Note Added: 0002900
2011-10-14 13:27 gienger Note Added: 0002901
2011-10-14 13:34 ludovic Note Added: 0002902
2011-10-14 13:36 gienger Note Added: 0002903
2011-10-14 13:36 gienger Note Edited: 0002903
2011-10-14 13:55 ludovic Note Added: 0002905
2011-10-14 17:49 ludovic Note Added: 0002910
2011-10-14 17:49 ludovic Status new => closed
2011-10-14 17:49 ludovic Resolution open => fixed
2011-10-14 17:49 ludovic Fixed in Version => 1.3.9