Relationship Graph

Relationship Graph
related to related to child of child of duplicate of duplicate of

View Issue Details

IDProjectCategoryView StatusLast Update
0005900SOGoBackend Mailpublic2024-02-22 10:03
ReporterrainerN Assigned Toqhivert  
PrioritynormalSeveritymajorReproducibilityrandom
Status closedResolutionfixed 
Product Version5.8.0 
Fixed in Version5.10.0 
Summary0005900: Mails get sent via SMTP but not stored in Sent-Folder
Description

About 90% cases of sending mail work fine, but it randomly happens that though the mail gets sent via smtp an error message shows "IMAP-error" and the mail cannot be stored in sent-folder. The user stays in editing mode and hits "Send" once again and everything works as expected. Mail is sent twice though as smtp works in both cases.

It took some time to find out what's causing this as in the sogo-logs they just show up as 405-errors on /send. As you can see in the attached log-snippets, the first imap session is missing the namespace command and tries to get the status for INBOXSent instead of INBOX.Sent which fails. But then it tries to create INBOX.Sent (with separator!?) and fails again.

Additional Information

Servers (sogo and imap): debian 12
sogo installed from debian-repository

Tagsimap

Relationships

related to 0005769 closedqhivert SOGo messes up IMAP subscriptions when randomly fails to open folder 

Activities

rainerN

rainerN

2023-11-10 09:57

reporter   ~0017420

This seems to be related to 0005769

rainerN

rainerN

2023-11-10 10:18

reporter   ~0017421

see logs

rainerN

rainerN

2023-11-10 10:28

reporter   ~0017422

IMAP-logs.txt.gz (1,096 bytes)
qhivert

qhivert

2023-11-10 11:04

administrator   ~0017423

Last edited: 2023-11-10 11:06

Hello,
There are several issues about that missing separator that happens sometime, and I've had a look at some point:

C: 4 LIST "" ""
R: * LIST (\Noselect) "." ""
R: 4 OK Completed (0.000 secs)
C: 5 status "INBOXSent" (UIDVALIDITY)
R: 5 NO Mailbox does not exist
C: 6 create "INBOX.Sent"

The delimiter is set when doing the LIST command, in all the cases we can see the delimiter (here it's "."). Then it's the same variable that is used for doing all the following command so I didn't understand how it was possible for it to be missing int the first command (status) but not in the second (create)...

However, could you add in your sogo.conf:
ImapLogEnabled = YES;
It may print some more logs that could help when this problem happens

rainerN

rainerN

2023-11-10 11:50

reporter   ~0017424

Hi,

Thanks for the quick response! As ImapLogEnabled didn't do anything, I set ImapDebugEnabled=Yes and this one worked.

I'm waiting for the error to show up again, will update this item when I have new results.

rainerN

rainerN

2023-11-13 10:25

reporter   ~0017427

Hello,

See the newly attached file containing corresponding logs from sogo- and imap-server.

qhivert

qhivert

2023-11-16 13:48

administrator   ~0017439

Hello,
Thanks for the log alas not new useful information or error. I would have to think a proper way to catch this error and understand why it happens.

rainerN

rainerN

2023-12-04 12:05

reporter   ~0017480

Hi,

No clues by now? Users get annoyed and start demanding to use a different mailing-client! Any workaround would be very welcome (e.g. setting something in a config-file, the database...)!

Tanks

qhivert

qhivert

2023-12-05 15:20

administrator   ~0017481

Well the best workaround would be to use the / instead of . as a imap delimiter. I've only see this issue with the . delimiter

rainerN

rainerN

2023-12-07 11:29

reporter   ~0017492

Thanks for the hint! We reconfigured imap-Server und sogo.

I'll keep you updated.

rainerN

rainerN

2023-12-08 09:57

reporter   ~0017493

Sorry, issue still exists!

Turned on IMAPDebug again.

qhivert

qhivert

2023-12-08 10:36

administrator   ~0017494

Do you use cyrus or dovecot?

rainerN

rainerN

2023-12-08 10:58

reporter   ~0017495

Cyrus IMAP 3.6.1-Debian-3.6.1-4+deb12u1

qhivert

qhivert

2023-12-08 11:06

administrator   ~0017496

Could you share your imapd.conf?

rainerN

rainerN

2023-12-08 11:25

reporter   ~0017497

sure:
configdirectory: /var/lib/cyrus
proc_path: /run/cyrus/proc
mboxname_lockpath: /run/cyrus/lock
defaultpartition: default
partition-default: /var/spool/cyrus/mail
partition-news: /var/spool/cyrus/news
newsspool: /var/spool/news
altnamespace: no
unixhierarchysep: yes
lmtp_downcase_rcpt: yes
allowanonymouslogin: no
popminpoll: 1
autocreate_quota: 524288
umask: 077
sieveusehomedir: false
sievedir: /var/spool/sieve
httpmodules: caldav carddav
hashimapspool: true
allowplaintext: yes
sasl_mech_list: PLAIN
sasl_pwcheck_method: saslauthd
lmtpsocket: /run/cyrus/socket/lmtp
idlesocket: /run/cyrus/socket/idle
notifysocket: /run/cyrus/socket/notify
syslog_prefix: cyrus
xlist-sent: Sent
xlist-drafts: Drafts
xlist-junk: Spam
xlist-templates: Templates
xlist-trash: Trash
allowusermoves: 1
imapidresponse: 0

imapd.conf (801 bytes)   
configdirectory: /var/lib/cyrus
proc_path: /run/cyrus/proc
mboxname_lockpath: /run/cyrus/lock
defaultpartition: default
partition-default: /var/spool/cyrus/mail
partition-news: /var/spool/cyrus/news
newsspool: /var/spool/news
altnamespace: no
unixhierarchysep: yes
lmtp_downcase_rcpt: yes
allowanonymouslogin: no
popminpoll: 1
autocreate_quota: 524288
umask: 077
sieveusehomedir: false
sievedir: /var/spool/sieve
httpmodules: caldav carddav
hashimapspool: true
allowplaintext: yes
sasl_mech_list: PLAIN
sasl_pwcheck_method: saslauthd
lmtpsocket: /run/cyrus/socket/lmtp
idlesocket: /run/cyrus/socket/idle
notifysocket: /run/cyrus/socket/notify
syslog_prefix: cyrus
xlist-sent: Sent
xlist-drafts: Drafts
xlist-junk: Spam
xlist-templates: Templates
xlist-trash: Trash
allowusermoves: 1
imapidresponse: 0
imapd.conf (801 bytes)   
rainerN

rainerN

2023-12-12 10:59

reporter   ~0017501

see new log (with / as delimiter)

sogo.log.txt.gz (428 bytes)
qhivert

qhivert

2023-12-18 15:44

administrator   ~0017508

Hello again
In the next nightly tomorrow, I've added more logs. Could you add this to your sogo.conf then restart sogod.
SOGoDebugRequests = YES;
ImapDebugEnabled = YES;
SOGoUIxDebugEnabled = YES;

Then give me the full log file when you see the problem.

qhivert

qhivert

2023-12-22 14:40

administrator   ~0017522

Hello, I've made a fix and another person said it was okay after that.
Could you install the last nightly and test it?
Just in case, add this to your sogo.conf:

SOGoDebugRequests = YES;
ImapDebugEnabled = YES;
SOGoUIxDebugEnabled = YES;
NGImap4ConnectionFolderDebugEnabled = YES;

So if it doesn't work, you could give me the log to see what happens.

rainerN

rainerN

2023-12-22 14:58

reporter   ~0017524

Sorry for being late...

I'll have to switch the system to nightly (we're on 5.8.0 as delivered with bookworm) and will only be able to do this after 08.01.2024.

I'll be back then to keep you updated again.

Happy hollidays and a happy new year!

rainerN

rainerN

2024-01-03 15:11

reporter   ~0017529

Switched to nightly and added the debug-settings to sogo.conf.

rainerN

rainerN

2024-01-16 15:51

reporter   ~0017532

Hi,

have been watching for more than one week. Error did'nt occur anymore, problem resolved!

Thanks a lot!

qhivert

qhivert

2024-01-16 15:54

administrator   ~0017533

Thanks for reporting!

Issue History

Date Modified Username Field Change
2023-11-10 09:56 rainerN New Issue
2023-11-10 09:56 rainerN Tag Attached: imap
2023-11-10 09:57 rainerN Note Added: 0017420
2023-11-10 10:18 rainerN Note Added: 0017421
2023-11-10 10:28 rainerN Note Added: 0017422
2023-11-10 10:28 rainerN File Added: IMAP-logs.txt.gz
2023-11-10 11:04 qhivert Note Added: 0017423
2023-11-10 11:04 qhivert Note Edited: 0017423
2023-11-10 11:05 qhivert Note Edited: 0017423
2023-11-10 11:05 qhivert Note Edited: 0017423
2023-11-10 11:05 qhivert Note Edited: 0017423
2023-11-10 11:06 qhivert Note Edited: 0017423
2023-11-10 11:06 qhivert Note Edited: 0017423
2023-11-10 11:06 qhivert Note Edited: 0017423
2023-11-10 11:06 qhivert Note View State: 0017423: public
2023-11-10 11:07 qhivert Assigned To => qhivert
2023-11-10 11:07 qhivert Status new => feedback
2023-11-10 11:50 rainerN Note Added: 0017424
2023-11-10 11:50 rainerN Status feedback => assigned
2023-11-13 10:25 rainerN Note Added: 0017427
2023-11-13 10:25 rainerN File Added: sogo.log+imap-log.txt.gz
2023-11-16 13:48 qhivert Note Added: 0017439
2023-12-04 12:05 rainerN Note Added: 0017480
2023-12-05 15:20 qhivert Note Added: 0017481
2023-12-07 11:29 rainerN Note Added: 0017492
2023-12-08 09:57 rainerN Note Added: 0017493
2023-12-08 10:36 qhivert Note Added: 0017494
2023-12-08 10:50 qhivert Status assigned => feedback
2023-12-08 10:58 rainerN Note Added: 0017495
2023-12-08 10:58 rainerN Status feedback => assigned
2023-12-08 11:06 qhivert Note Added: 0017496
2023-12-08 11:06 qhivert Status assigned => feedback
2023-12-08 11:25 rainerN Note Added: 0017497
2023-12-08 11:25 rainerN File Added: imapd.conf
2023-12-08 11:25 rainerN Status feedback => assigned
2023-12-12 10:59 rainerN Note Added: 0017501
2023-12-12 10:59 rainerN File Added: sogo.log.txt.gz
2023-12-18 15:44 qhivert Note Added: 0017508
2023-12-18 15:44 qhivert Status assigned => feedback
2023-12-18 15:45 qhivert Relationship added related to 0005769
2023-12-22 14:40 qhivert Note Added: 0017522
2023-12-22 14:58 rainerN Note Added: 0017524
2023-12-22 14:58 rainerN Status feedback => assigned
2024-01-03 15:11 rainerN Note Added: 0017529
2024-01-16 15:51 rainerN Note Added: 0017532
2024-01-16 15:54 qhivert Note Added: 0017533
2024-01-16 15:54 qhivert Status assigned => resolved
2024-01-16 15:54 qhivert Resolution open => fixed
2024-01-16 15:54 qhivert Fixed in Version => 5.10.0
2024-02-22 10:03 qhivert Status resolved => closed