Mailproblems with Sogo

[hucky (kai)]

NethServer Version: NethServer release 7.4.1708
Module: Sogo, Rspamd

I notized some Problems with Sogo after the last Update. I am on
|sogo|4.0.0|1.ns7
|sogo-activesync|4.0.0|1.ns7|
|sogo-ealarms-notify|4.0.0|1.ns7|
|sogo-tool|4.0.0|1.ns7|

When i receive Emails like for Example from Facebook, it says without a Sender and is not showed in Outlook. Another Email i received was not shown in IOS Mail App, or Android Mail App and also not in Outlook, the Mails are not declared as Spam. In the Webgui of Sogo i see the Mail but only the Sender, not the Mailtext.

But not all Emails are that way…

[stephdl (Stéphane de Labrusse)]

HI

sogo is just a mail client, IIUC you have similar issue with other mail clients, it makes me think that the key of the issue is not sogo but your mail server. Nothing in maillog ?

EDIT: I cannot reproduce the issue with sogo4 and ns7.4

[hucky (kai)]

hmm, nothing what makes sense to me…

May 13 11:20:02 sbs rspamd[3087]: <fd6de5>; csession; rspamd_message_parse: loaded message; id: <topic/9842/63391@community.nethserver.org>; queue-id: <undef>; size: 8190; checksum: <7f88c09f4a0a498e50c7446d6c8fa73f>
May 13 11:20:02 sbs rspamd[3087]: <fd6de5>; csession; fuzzy_generate_commands: <topic/9842/63391@community.nethserver.org>, part is shorter than 1000 bytes: 810 (405 * 2.00 bytes), skip fuzzy check
May 13 11:20:02 sbs rspamd[3087]: <fd6de5>; csession; fuzzy_generate_commands: <topic/9842/63391@community.nethserver.org>, part is shorter than 1000 bytes: 810 (405 * 2.00 bytes), use direct hash 
May 13 11:20:03 sbs rspamd[3087]: <fd6de5>; lua; antivirus.lua:480: failed to scan: IO read error while trying to read data: Connection reset by peer 
May 13 11:20:06 sbs rspamd[3087]: <fd6de5>; csession; fuzzy_check_timer_callback: got IO timeout with server fuzzy.rspamd.com(88.99.142.95), after 1 retransmits 
May 13 11:20:06 sbs rspamd[3087]: <fd6de5>; csession; bayes_classify: skip classification as spam class has not enough learns: 63, 200 required 
May 13 11:20:06 sbs rspamd[3087]: <fd6de5>; lua; greylist.lua:255: Score too low - skip greylisting 
May 13 11:20:06 sbs rspamd[3087]: <fd6de5>; csession; rspamd_task_write_log: id: <topic/9842/63391@community.nethserver.org>, ip: 212.227.17.5, from: <nethserverdiscourse@gmail.com>, (default: F (no action): [0.08/15.00] 
[MV_CASE(0.50){},R_DKIM_ALLOW(-0.20){discoursehosting.com;},MAILLIST(-0.10){generic;},MIME_GOOD(-0.10){multipart/alternative;text/plain;},HAS_LIST_UNSUB(-0.01){},MX_GOOD(-0.01){alt1.gmail-smtp-in.l.google.com;},ASN(0.00){asn:8560, 
ipnet:212.227.0.0/16, country:DE;},CLAMAV_FAIL(0.00){failed to scan;},DKIM_TRACE(0.00){discoursehosting.com:+;},DMARC_NA(0.00){nethserver.org;},FREEMAIL_ENVFROM(0.00){gmail.com;},FREEMAIL_ENVRCPT(0.00){gmx.de;},FREEMAIL_REPLYTO(0.00)
{gmail.com;},FREEMAIL_TO(0.00){gmx.de;},FROM_HAS_DN(0.00){},FROM_NEQ_ENVFROM(0.00){alessio.fattorini@nethserver.org;nethserverdiscourse@gmail.com;},HAS_REPLYTO(0.00)
{nethserver.discourse+09deb1a942c17b43fee8079b7f088437@gmail.com;},PREVIOUSLY_DELIVERED(0.00){xxx@gmx.de;},RCPT_COUNT_ONE(0.00){1;},RCVD_COUNT_ONE(0.00){1;},RCVD_IN_DNSWL_LOW(0.00){5.17.227.212.list.dnswl.org : 
127.0.3.1;},RCVD_TLS_ALL(0.00){},REPLYTO_DOM_NEQ_FROM_DOM(0.00){},R_SPF_SOFTFAIL(0.00){~all;},TAGGED_FROM(0.00){verp-42a68aaccae7db1cf270f7e349105b90;},TO_DN_NONE(0.00){}]), len: 8190, time: 4224.033ms real, 14.803ms virtual, dns req: 
35, digest: <7f88c09f4a0a498e50c7446d6c8fa73f>, mime_rcpts: <xxx@gmx.de>, file: stdin 
May 13 11:20:06 sbs rspamd[3087]: <fd6de5>; csession; rspamd_protocol_http_reply: regexp statistics: 86 pcre regexps scanned, 3 regexps matched, 172 regexps total, 10 regexps cached, 19.06k bytes scanned using pcre, 19.06k bytes scanned total
May 13 11:20:06 sbs dovecot: lda(xxx@xxxxxxx.lan): sieve: msgid=<topic/9842/63391@community.nethserver.org>: stored mail into mailbox 'INBOX'
May 13 11:20:06 sbs getmail: msg 1/1 (8361 bytes) msgid 0MbALX-1eytPI0uYl-00KhB0 from <nethserver.discourse+verp-42a68aaccae7db1cf270f7e349105b90@gmail.com> delivered to MDA_external command dovecot-lda (), deleted 
May 13 11:20:56 sbs rspamd[3087]: <3d89ch>; lua; neural.lua:813: check ANN tRFANN41F3D208416AF2B1260 
May 13 11:20:56 sbs rspamd[3087]: <3d89ch>; lua; neural.lua:825: no need to learn ANN tRFANN41F3D208416AF2B1260 0 learn vectors (1000 required) 
May 13 11:21:56 sbs rspamd[3087]: <3d89ch>; lua; neural.lua:813: check ANN tRFANN41F3D208416AF2B1260 
May 13 11:21:56 sbs rspamd[3087]: <3d89ch>; lua; neural.lua:825: no need to learn ANN tRFANN41F3D208416AF2B1260 0 learn vectors (1000 required)

[stephdl (Stéphane de Labrusse)]

@hucky

hmm, nothing what makes sense to me…

martians is easier to read

for formatting (thank) you could use also gist → https://gist.github.com/

It is better sometime

Find the relevant part by the email sender and the time, and report back please

[hucky (kai)]

i am to stupid for a right format, lol, but still fighting for it

[stephdl (Stéphane de Labrusse)]

Not stupid, but sometime system administrator think that developers are super heros

please help us to help you

[hucky (kai)]

sorry for that, but i guess it is readable. this happen as i receive a mail from nethserver where you respond to my post here

[stephdl (Stéphane de Labrusse)]

you use getmail …how did you installed your mail server please

[hucky (kai)]

normal over the softwarecenter… i know we had made changes as we test around with rspamd

[hucky (kai)]

maybe it is not a sogo or rspamd problem, its wired. with outlook i get the info new mail, but it is not shown, in sogo client everything seems ok, with android also, with ios not. at ios app it shows mail not load from server

[stephdl (Stéphane de Labrusse)]

could you check the source email in /var/lib/nethserver

find the email by the sender, for instance

grep -srni 'info@shalleged.com' /var/lib/nethserver/vmail/stephane\@de-labrusse.fr/Maildir/

check the permission, check the content of the email

this is what I have

[root@prometheus ~]# ll /var/lib/nethserver/vmail/stephane@de-labrusse.fr/Maildir/cur/1523692767.M813784P1883.prometheus.de-labrusse.fr,S=4857,W=4961:2,Sg

[hucky (kai)]

i got:
/var/lib/nethserver/vmail/xxx@xxx-xxx.lan/Maildir/.Sent/cur/1512747092.M228 730P21470.xxx.xxx-xxx.lan,S=201392,W=206032:2,S:643:From: =?UTF-8?Q?St=C3=A9ph ane_de_Labrusse?= alessio.fattorini@nethserver.org

i think that something is blocking only some mails since the Update cause older Emails from Nethserver Comunity are shown normal. Only the last ones, since the Update are not shown in Outlook and in the IOS Mail App. Funny is also that Outlook has the right Number of Emails, when i delete one over the Webgui of Sogo, where everything is shown well, it reduce also in the Outlook Client the Number of Emails, and other Emails are shown correct without Problems.

[stephdl (Stéphane de Labrusse)]

You spoke about which update, sogo is just an email client, it doesn’t modify the email you receive and the way of other email client read the emails.

Did you upgrade to centos7.5 ?

If really you want to be sure, remove sogo and nethserver-sogo and see how you receive the email

[hucky (kai)]

i spoke about an Update i think 2 days ago, it was sogo and also the mail2 stuff. I did not upgrade to centos 7.5.

I guess figured out that if i receive Emails from a normal Sender everything seems to be ok, but if i receive from something like a Maillist it seems there is a Problem.

Okay, will check it

[hucky (kai)]

I have checked my old logs also and after the Update i got errors, maybe there is the Point for understand what happen.

Before the Update:

May 11 07:26:41 sogod [1958]: 192.168.100.140 “POST /SOGo/Microsoft-Server-ActiveSync?User=xxx&DeviceId=5A2EQFMDI95VP3MG1JADOBK78G&DeviceType=iPad&Cmd=Sync HTTP/1.1” 200 550/72 0.165 - - 68K
May 11 07:26:41 sogod [1958]: 192.168.100.140 “POST /SOGo/Microsoft-Server-ActiveSync?User=xxx&DeviceId=5A2EQFMDI95VP3MG1JADOBK78G&DeviceType=iPad&Cmd=Sync HTTP/1.1” 200 0/71 0.047 - - 0
May 11 07:26:41 sogod [1968]: <0x0x561c2403c040[NGImap4Client]> Note: no key found for sorting, using ‘DATE’: (null)
May 11 07:26:41 sogod [1963]: <0x0x561c2409d360[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user xxx in Ping…
May 11 07:26:41 sogod [1958]: <0x0x561c24364c10[SOGoActiveSyncDispatcher]> Change detected during Sync, we push the content.

After the Update:

May 15 09:30:11 sogod [28344]: 192.168.100.140 “POST /SOGo/Microsoft-Server-ActiveSync?User=xxx&DeviceId=5A2EQFMDI95VP3MG1JADOBK78G&DeviceType=iPad&Cmd=Sync HTTP/1.1” 200 437/110 0.890 - - 0

May 15 09:30:12 sogod [28344]: <0x0x559ca62b2850[NGImap4Client]> ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched non-IMAP4 parsing exception NGCouldNotOpenStreamException: could not open stream

May 15 09:30:12 sogod [28344]: <0x0x559ca62b2850[NGImap4Client]> ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched non-IMAP4 parsing exception NGCouldNotOpenStreamException: could not open stream

May 15 09:30:12 sogod [28344]: [ERROR] <0x0x559ca74dc900[NGImap4Connection]> could not fetch url: imap://xxx%40xxx.lan@localhost/INBOX/33303

And from the Outlook Side i saw that in the Past the Cliet was recognized with the rigth IP Number now it took the IP Number of the Sogo Server

Before Update:
May 11 07:27:12 sogod [1968]: 192.168.100.117 “POST /SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync&User=xxx&DeviceId=6FD670FE709A4BDC8F6644AAB1E5B5D8&DeviceType=WindowsOutlook15 HTTP/1.1” 200 56/44 0.872 - - 3M

After Update
192.168.100.5 “POST /SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync&User=xxx&DeviceId=6FD670FE709A4BDC8F6644AAB1E5B5D8&DeviceType=WindowsOutlook15 HTTP/1.1” 200 56/44 0.496 - - -944K

And sorry cause i guess the format is again horrible and it is not for making Trouble here, just for inform and maybe learn (especial me)

[Stefano_Zamboni]

@stephdl

Not stupid, but sometime system administrator think that developers are super heros

I’d say that more often it’s the contrary
devs think that a sysadmin can read and understand every kind of log (SOGo’s ones docet)

[hucky (kai)]

Okay, i guess i got it (also just to inform) i saw after e restart of the server this:

2018-05-15 10:08:39.028 sogod[2104:2104] ERROR: could not open MySQL4 connection to database ‘sogo’: Can’t connect to local MySQL server through socket ‘/var/lib/mysql/mysql.sock’ (2) May 15 10:08:39 sogod [2104]: [ERROR] <0x0x55f96aec92b0[GCSChannelManager]> could not open channel <MySQL4Channel[0x0x55f96b0b39d0] connection=0x(null)> for mysql://localhost/sogo/sogo_user_profile May 15 10:08:39 sogod [2104]: [WARN] <0x0x55f96aec92b0[GCSChannelManager]> will prevent opening of this channel 5 seconds after 2018-05-15 10:08:38 +0200 M

i search in the forum and found this workaround from @dnutan

Sogo sql Error after install

The previous tweak has an undesired side-effect. This correction might fix it: Create and edit a drop-in systemd conf for sogo service: mkdir -p /etc/systemd/system/sogod.service.d/ vi /etc/systemd/system/sogod.service.d/mariadb.conf with the following content: [Unit] # Wait for mariadb/mysqld service # see http://community.nethserver.org/t/sogo-sql-error-after-install/6407 After=mariadb.service mysqld.service Apply the changes: systemctl daemon-reload Reboot the server to evaluate the who…

After e restart it seems to work… what i dont get is why it changed…