mailcow / mailcow-dockerized

mailcow: dockerized - 🐮 + 🐋 = 💕
https://mailcow.email
GNU General Public License v3.0
8.34k stars 1.13k forks source link

Calendar invitation is send multiple times #4975

Closed crstmkt closed 1 year ago

crstmkt commented 1 year ago

Contribution guidelines

I've found a bug and checked that ...

Description

I have a full set up Mailcow Server with two mails configured: One for me, one for my girl. When my girl creates an appointment (on her iPhone in her calendar - configured using EAS for Mailcow) an invites me to that appointment (so it will also appear in my calendar), the invitation will be send to me multiple times, on and on once every hour. Not depending on wheter I already accepted that invitation or not. That invitation keeps on popping up in my inbox. it is also reproduceable when she sends the invitation to another mailadress (eg. @live.com) or If I send an invitation to her, she receives the invitation multiple times.

Logs:

mailcowdockerized-rspamd-mailcow-1  | 2023-01-10 09:11:15 #45(controller) <fabfee>; csession; rspamd_redis_connected: skip obtaining bayes tokens for BAYES_SPAM of classifier bayes: not enough learns 0; 5 required
mailcowdockerized-rspamd-mailcow-1  | 2023-01-10 09:11:15 #45(controller) <fabfee>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3286 regexps total, 2457 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowdockerized-rspamd-mailcow-1  | 2023-01-10 09:12:07 #45(controller) <8844b8>; csession; rspamd_redis_connected: skip obtaining bayes tokens for BAYES_HAM of classifier bayes: not enough learns 3; 5 required
mailcowdockerized-rspamd-mailcow-1  | 2023-01-10 09:12:07 #45(controller) <8844b8>; csession; rspamd_redis_connected: skip obtaining bayes tokens for BAYES_SPAM of classifier bayes: not enough learns 0; 5 required
mailcowdockerized-rspamd-mailcow-1  | 2023-01-10 09:12:07 #45(controller) <8844b8>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3286 regexps total, 2457 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowdockerized-acme-mailcow-1    | Mon Jan  9 12:29:12 CET 2023 - SKIP_LETS_ENCRYPT=y, skipping Let's Encrypt...
mailcowdockerized-dovecot-mailcow-1  | Jan 10 09:12:50 4fa9aaee65bf dovecot: imap(chris@mydomain.tld)<289265><wCohc+Tx0r2sFgH4>: Disconnected: Logged out in=228 out=3647 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
mailcowdockerized-dovecot-mailcow-1  | Jan 10 09:12:50 4fa9aaee65bf dovecot: imap-login: Login: user=<chris@mydomain.tld>, method=PLAIN, rip=172.22.1.248, lip=172.22.1.250, mpid=289267
mailcowdockerized-dovecot-mailcow-1  | Jan 10 09:12:50 4fa9aaee65bf dovecot: imap(chris@mydomain.tld)<289267><nqEoc+Tx1L2sFgH4>: Disconnected: Logged out in=228 out=3647 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
mailcowdockerized-dovecot-mailcow-1  | Jan 10 09:12:50 4fa9aaee65bf dovecot: imap-login: Login: user=<chris@mydomain.tld>, method=PLAIN, rip=172.22.1.248, lip=172.22.1.250, mpid=289269
mailcowdockerized-dovecot-mailcow-1  | Jan 10 09:12:51 4fa9aaee65bf dovecot: imap(chris@mydomain.tld)<289269><zNUvc+TxYtysFgH4>: Disconnected: Logged out in=228 out=3647 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
mailcowdockerized-ofelia-mailcow-1   | 2023-01-10T09:12:14.024+01:00  common.go:125 ▶ NOTICE [Job "dovecot_trim_logs" (7407834e4747)] Started - /bin/bash -c "[[ ${MASTER} == y ]] && /usr/local/bin/gosu vmail /usr/local/bin/trim_logs.sh || exit 0"
mailcowdockerized-ofelia-mailcow-1   | 2023-01-10T09:12:14.233+01:00  common.go:125 ▶ NOTICE [Job "dovecot_imapsync_runner" (4773f0fcf6bf)] Finished in "215.204383ms", failed: false, skipped: false, error: none
mailcowdockerized-ofelia-mailcow-1   | 2023-01-10T09:12:14.32+01:00  common.go:125 ▶ NOTICE [Job "sogo_ealarms" (836bece5ac42)] Finished in "303.857094ms", failed: false, skipped: false, error: none
mailcowdockerized-ofelia-mailcow-1   | 2023-01-10T09:12:14.329+01:00  common.go:125 ▶ NOTICE [Job "dovecot_trim_logs" (7407834e4747)] Finished in "304.770382ms", failed: false, skipped: false, error: none
mailcowdockerized-ofelia-mailcow-1   | 2023-01-10T09:12:14.402+01:00  common.go:125 ▶ NOTICE [Job "sogo_sessions" (8e1d7313b3ee)] Finished in "380.733997ms", failed: false, skipped: false, error: none
mailcowdockerized-netfilter-mailcow-1  | 9 more attempts in the next 600 seconds until 46.148.40.183/32 is banned
mailcowdockerized-netfilter-mailcow-1  | 141.98.10.106 matched rule id 3 (warning: unknown[141.98.10.106]: SASL LOGIN authentication failed: UGFzc3dvcmQ6)
mailcowdockerized-netfilter-mailcow-1  | 9 more attempts in the next 600 seconds until 141.98.10.106/32 is banned
mailcowdockerized-netfilter-mailcow-1  | 141.98.11.93 matched rule id 3 (warning: unknown[141.98.11.93]: SASL LOGIN authentication failed: UGFzc3dvcmQ6)
mailcowdockerized-netfilter-mailcow-1  | 9 more attempts in the next 600 seconds until 141.98.11.93/32 is banned
traefik_certdumper                     | [2023-01-09T11:29:08+0000]: Values split! Got 'mail.mydomain.tld'
traefik_certdumper                     | [2023-01-09T11:29:08+0000]: ACME file path: /traefik/acme.json
traefik_certdumper                     | [2023-01-09T11:29:08+0000]: Clearing dumping directory
traefik_certdumper                     | [2023-01-09T11:29:08+0000]: Dumping certificates
traefik_certdumper                     | [2023-01-09T11:29:09+0000]: Certificate and key for 'mail.mydomain.tld' still up to date, doing nothing
mailcowdockerized-php-fpm-mailcow-1    | fd4d:6169:6c63:6f77::f - chris@mydomain.tld 10/Jan/2023:09:12:49 +0100 "GET /sogo-auth.php" 200
mailcowdockerized-php-fpm-mailcow-1    | 172.22.1.10 - chris@mydomain.tld 10/Jan/2023:09:12:50 +0100 "GET /sogo-auth.php" 200
mailcowdockerized-php-fpm-mailcow-1    | fd4d:6169:6c63:6f77::f -  10/Jan/2023:09:12:50 +0100 "HEAD /forwardinghosts.php" 200
mailcowdockerized-php-fpm-mailcow-1    | fd4d:6169:6c63:6f77::f -  10/Jan/2023:09:12:50 +0100 "GET /forwardinghosts.php" 200
mailcowdockerized-php-fpm-mailcow-1    | fd4d:6169:6c63:6f77::f - chris@mydomain.tld 10/Jan/2023:09:12:50 +0100 "GET /sogo-auth.php" 200
mailcowdockerized-redis-mailcow-1      | 1:M 10 Jan 2023 09:08:17.046 * 100 changes in 300 seconds. Saving...
mailcowdockerized-redis-mailcow-1      | 1:M 10 Jan 2023 09:08:17.048 * Background saving started by pid 262
mailcowdockerized-redis-mailcow-1      | 262:C 10 Jan 2023 09:08:17.102 * DB saved on disk
mailcowdockerized-redis-mailcow-1      | 262:C 10 Jan 2023 09:08:17.103 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
mailcowdockerized-redis-mailcow-1      | 1:M 10 Jan 2023 09:08:17.149 * Background saving terminated with success
mailcowdockerized-mysql-mailcow-1      | 2023-01-09 12:29:11 0 [Note] Server socket created on IP: '::'.
mailcowdockerized-mysql-mailcow-1      | 2023-01-09 12:29:11 1 [Note] Event Scheduler: scheduler thread started with id 1
mailcowdockerized-mysql-mailcow-1      | 2023-01-09 12:29:11 0 [Note] mysqld: ready for connections.
mailcowdockerized-mysql-mailcow-1      | Version: '10.5.18-MariaDB-1:10.5.18+maria~ubu2004'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
mailcowdockerized-mysql-mailcow-1      | 2023-01-09 12:29:11 0 [Note] InnoDB: Buffer pool(s) load completed at 230109 12:29:11
mailcowdockerized-solr-mailcow-1       | 2023-01-10 08:02:29.195 INFO  (qtp1399701152-16) [   x:dovecot-fts] o.a.s.u.p.LogUpdateProcessorFactory [dovecot-fts]  webapp=/solr path=/update params={}{commit=} 0 16
mailcowdockerized-watchdog-mailcow-1   | Tue Jan 10 09:12:31 CET 2023 Nginx health level: 100% (5/5), health trend: 0
mailcowdockerized-watchdog-mailcow-1   | Tue Jan 10 09:12:33 CET 2023 Dovecot replication health level: 100% (20/20), health trend: 0
mailcowdockerized-watchdog-mailcow-1   | Tue Jan 10 09:12:36 CET 2023 Unbound health level: 100% (5/5), health trend: 0
mailcowdockerized-watchdog-mailcow-1   | Tue Jan 10 09:12:37 CET 2023 SOGo health level: 100% (3/3), health trend: 0
mailcowdockerized-dockerapi-mailcow-1  | -----
mailcowdockerized-dockerapi-mailcow-1  | INFO:     Started server process [8]
mailcowdockerized-dockerapi-mailcow-1  | INFO:     Waiting for application startup.
mailcowdockerized-dockerapi-mailcow-1  | INFO:     Application startup complete.
mailcowdockerized-dockerapi-mailcow-1  | INFO:     Uvicorn running on https://0.0.0.0:443 (Press CTRL+C to quit)
mailcowdockerized-olefy-mailcow-1      | olefy INFO <module> olefy log level: 20
mailcowdockerized-olefy-mailcow-1      | olefy INFO <module> olefy min file length: 500
mailcowdockerized-olefy-mailcow-1      | olefy INFO <module> olefy delete tmp file: 1
mailcowdockerized-olefy-mailcow-1      | olefy INFO <module> olefy delete tmp file when failed: 1
mailcowdockerized-olefy-mailcow-1      | olefy INFO <module> serving on ('0.0.0.0', 10055)
mailcowdockerized-nginx-mailcow-1      | 91.62.85.198 - chris@mydomain.tld [10/Jan/2023:09:12:50 +0100] "POST /Microsoft-Server-ActiveSync?User=chris@mydomain.tld&DeviceId=UIKQ0UUQ2P20VFK4LURC500NFK&DeviceType=iPad&Cmd=Sync HTTP/1.1" 200 0 "-" "Apple-iPad13C6/2003.65"
mailcowdockerized-nginx-mailcow-1      | fd4d:6169:6c63:6f77::12 - - [10/Jan/2023:09:12:50 +0100] "HEAD /forwardinghosts.php HTTP/1.1" 200 0 "-" "rspamd-3.4"
mailcowdockerized-nginx-mailcow-1      | 172.22.1.13 - - [10/Jan/2023:09:12:50 +0100] "GET /forwardinghosts.php HTTP/1.1" 200 27 "-" "rspamd-3.4"
mailcowdockerized-nginx-mailcow-1      | 127.0.0.1 - chris@mydomain.tld [10/Jan/2023:09:12:50 +0100] "GET /sogo-auth HTTP/1.0" 200 0 "-" "Apple-iPad13C6/2003.65"
mailcowdockerized-nginx-mailcow-1      | 91.62.85.198 - chris@mydomain.tld [10/Jan/2023:09:12:51 +0100] "POST /Microsoft-Server-ActiveSync?User=chris@mydomain.tld&DeviceId=UIKQ0UUQ2P20VFK4LURC500NFK&DeviceType=iPad&Cmd=Sync HTTP/1.1" 200 0 "-" "Apple-iPad13C6/2003.65"
mailcowdockerized-solr-mailcow-1       | 2023-01-10 08:02:43.594 INFO  (commitScheduler-13-thread-1) [   ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
mailcowdockerized-solr-mailcow-1       | 2023-01-10 08:02:43.594 INFO  (commitScheduler-13-thread-1) [   ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@6c6efa2e commitCommandVersion:0
mailcowdockerized-solr-mailcow-1       | 2023-01-10 08:02:43.614 INFO  (commitScheduler-13-thread-1) [   ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6ea62b93[dovecot-fts] realtime]
mailcowdockerized-solr-mailcow-1       | 2023-01-10 08:02:43.616 INFO  (commitScheduler-13-thread-1) [   ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
mailcowdockerized-postfix-mailcow-1    | Jan 10 09:12:29 94f5ee81139c postfix/submission/smtpd[6343]: warning: unknown[141.98.11.93]: SASL LOGIN authentication failed: UGFzc3dvcmQ6
mailcowdockerized-postfix-mailcow-1    | Jan 10 09:12:29 94f5ee81139c postfix/submission/smtpd[6343]: disconnect from unknown[141.98.11.93] ehlo=2 starttls=1 auth=0/1 quit=1 commands=4/5
mailcowdockerized-postfix-mailcow-1    | Jan 10 09:12:41 94f5ee81139c postfix/smtps/smtpd[6241]: Anonymous TLS connection established from rkt5.sacramentsturgid.com[141.98.11.43]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
mailcowdockerized-postfix-mailcow-1    | Jan 10 09:12:45 94f5ee81139c postfix/smtps/smtpd[6271]: connect from unknown[46.148.40.95]
mailcowdockerized-postfix-mailcow-1    | Jan 10 09:12:48 94f5ee81139c postfix/smtps/smtpd[6271]: Anonymous TLS connection established from unknown[46.148.40.95]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
mailcowdockerized-watchdog-mailcow-1   | Tue Jan 10 09:12:38 CET 2023 Postfix health level: 100% (8/8), health trend: 0
mailcowdockerized-clamd-mailcow-1      | Tue Jan 10 08:38:51 2023 -> instream(172.22.1.13@49480): OK
mailcowdockerized-clamd-mailcow-1      | Tue Jan 10 08:49:24 2023 -> instream(172.22.1.13@59124): OK
mailcowdockerized-clamd-mailcow-1      | Tue Jan 10 08:50:40 2023 -> instream(172.22.1.13@42488): OK
mailcowdockerized-clamd-mailcow-1      | Tue Jan 10 08:54:40 2023 -> instream(172.22.1.13@47028): OK
mailcowdockerized-clamd-mailcow-1      | Tue Jan 10 08:54:46 2023 -> instream(172.22.1.13@45070): OK
mailcowdockerized-sogo-mailcow-1       | Jan 10 09:12:49 9fbe6a664eb1 sogod [29712]: 91.62.85.198, 91.62.85.198 "POST /SOGo/Microsoft-Server-ActiveSync?User=chris@mydomain.tld&DeviceId=UIKQ0UUQ2P20VFK4LURC500NFK&DeviceType=iPad&Cmd=Sync HTTP/1.0" 200 0/68 0.190 - - 0 - 13
mailcowdockerized-sogo-mailcow-1       | Jan 10 09:12:49 9fbe6a664eb1 sogod [29712]: 91.62.85.198, 91.62.85.198 "POST /SOGo/Microsoft-Server-ActiveSync?User=chris@mydomain.tld&DeviceId=UIKQ0UUQ2P20VFK4LURC500NFK&DeviceType=iPad&Cmd=Sync HTTP/1.0" 200 0/68 0.167 - - 0 - 13
mailcowdockerized-sogo-mailcow-1       | Jan 10 09:12:50 9fbe6a664eb1 sogod [29712]: 91.62.85.198, 91.62.85.198 "POST /SOGo/Microsoft-Server-ActiveSync?User=chris@mydomain.tld&DeviceId=UIKQ0UUQ2P20VFK4LURC500NFK&DeviceType=iPad&Cmd=Sync HTTP/1.0" 200 0/68 0.167 - - 0 - 13
mailcowdockerized-sogo-mailcow-1       | Jan 10 09:12:50 9fbe6a664eb1 sogod [29712]: 91.62.85.198, 91.62.85.198 "POST /SOGo/Microsoft-Server-ActiveSync?User=chris@mydomain.tld&DeviceId=UIKQ0UUQ2P20VFK4LURC500NFK&DeviceType=iPad&Cmd=Sync HTTP/1.0" 200 0/68 0.157 - - 0 - 13
mailcowdockerized-sogo-mailcow-1       | Jan 10 09:12:51 9fbe6a664eb1 sogod [29712]: 91.62.85.198, 91.62.85.198 "POST /SOGo/Microsoft-Server-ActiveSync?User=chris@mydomain.tld&DeviceId=UIKQ0UUQ2P20VFK4LURC500NFK&DeviceType=iPad&Cmd=Sync HTTP/1.0" 200 0/68 0.165 - - 0 - 13
mailcowdockerized-unbound-mailcow-1    | [1673263756] unbound[1:0] notice: init module 0: validator
mailcowdockerized-unbound-mailcow-1    | [1673263756] unbound[1:0] notice: init module 1: iterator
mailcowdockerized-unbound-mailcow-1    | [1673263756] unbound[1:0] info: start of service (unbound 1.17.0).
mailcowdockerized-unbound-mailcow-1    | [1673263761] unbound[1:0] info: generate keytag query _ta-4f66. NULL IN
mailcowdockerized-unbound-mailcow-1    | [1673304507] unbound[1:0] info: generate keytag query _ta-4f66. NULL IN

Steps to reproduce:

1. Create an appointment on your iPhone. Assume you are using your mailcow calendar as your primary calendar
2. send an invitation for that appointment to aany other mailadress
3. the invitation is send (or received?) multiple times

Which branch are you using?

master

Operating System:

Debian 11

Server/VM specifications:

16GB RAM, 800GB SSD, 8 Cores

Is Apparmor, SELinux or similar active?

no

Virtualization technology:

KVM

Docker version:

20.10.18

docker-compose version or docker compose version:

2.9.0

mailcow version:

2022-12

Reverse proxy:

Traefik

Logs of git diff:

no diffs

Logs of iptables -L -vn:

not posted because "body is too long"

Logs of ip6tables -L -vn:

not posted because "body is too long"

Logs of iptables -L -vn -t nat:

not posted because "body is too long"

Logs of ip6tables -L -vn -t nat:

not posted because "body is too long"

DNS check:

not posted because "body is too long"
crstmkt commented 1 year ago

I made a few tests and can now confirm, that this behaviour only happens, when the invitation was sent trough an iOS device. What I tested is:

  1. Create an appointment in SOGo and send invitation trough SOGo -> OK
  2. Create an Appointment in iOS Calendar App and send invitation trough SOGo -> OK
  3. Create an appointment on iOS and send invitation trough iOS -> invitation sent multiple times
milkmaker commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.