Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ActiveSync and webmail freez #937

Closed
chalupal opened this issue Sep 16, 2016 · 10 comments
Closed

ActiveSync and webmail freez #937

chalupal opened this issue Sep 16, 2016 · 10 comments

Comments

@chalupal
Copy link

chalupal commented Sep 16, 2016 •
edited
Loading

I have an issue with newly installed Mail In a Box system. All users are connected thru activesync. Connection works 15 minutes and than every approx 15 minutes it shows demand on password and the klient is disconnected from server. If the password is newly set, it doesnt solve the problem. When try to acces to wemail servis, it shows error Gateway time out..... If the service nginx is restarted everythings is ok, but only for approx 15 minutes and the problem is here again. Logfile nginx has 20 MB after 3 days of usage.

the part of Nginx error log:

2016/09/16 00:02:19 [error] 32594#0: *6637 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 109.71.214.111, server: mail.l-system.cloud, request: "POST /Microsoft-Server-ActiveSync?Cmd=Ping&User=lukas.chalupa%40l-system.cloud&DeviceId=androidc887432949&DeviceType=Android HTTP/1.1", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "mail.l-system.cloud"
2016/09/16 00:02:51 [error] 32594#0: *6639 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 109.71.214.111, server: mail.l-system.cloud, request: "POST /Microsoft-Server-ActiveSync?Cmd=ItemOperations&User=stepanka.zuskova%40svjokruzni.cz&DeviceId=androidc195792594&DeviceType=Android HTTP/1.1", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "mail.l-system.cloud"
2016/09/16 00:03:11 [error] 32594#0: *6641 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 109.71.214.111, server: mail.l-system.cloud, request: "POST /Microsoft-Server-ActiveSync?Cmd=Ping&User=lukas.chalupa%40l-system.cloud&DeviceId=androidc887432949&DeviceType=Android HTTP/1.1", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "mail.l-system.cloud"
2016/09/16 00:03:51 [error] 32594#0: *6643 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 109.71.214.111, server: mail.l-system.cloud, request: "POST /Microsoft-Server-ActiveSync?Cmd=ItemOperations&User=stepanka.zuskova%40svjokruzni.cz&DeviceId=androidc195792594&DeviceType=Android HTTP/1.1", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "mail.l-system.cloud"
2016/09/16 00:04:00 [error] 32594#0: *6645 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:01 [error] 32594#0: *6649 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:01 [error] 32594#0: *6653 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:01 [error] 32594#0: *6657 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:30 [error] 32594#0: *6663 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:30 [error] 32594#0: *6667 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:30 [error] 32594#0: *6647 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"
2016/09/16 00:04:30 [error] 32594#0: *6671 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:31 [error] 32594#0: *6651 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"
2016/09/16 00:04:31 [error] 32594#0: *6655 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"
2016/09/16 00:04:31 [error] 32594#0: *6659 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"
2016/09/16 00:04:49 [error] 32594#0: *6675 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /caldav/calendars/[email protected]/ HTTP/1.1", upstream: "https://127.0.0.1:443/cloud/remote.php/caldav/calendars/[email protected]/", host: "127.0.0.1"
2016/09/16 00:04:51 [error] 32594#0: *6661 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 109.71.214.111, server: mail.l-system.cloud, request: "POST /Microsoft-Server-ActiveSync?Cmd=ItemOperations&User=stepanka.zuskova%40svjokruzni.cz&DeviceId=androidc195792594&DeviceType=Android HTTP/1.1", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "mail.l-system.cloud"
2016/09/16 00:05:00 [error] 32594#0: *6665 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"
2016/09/16 00:05:00 [error] 32594#0: *6669 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"
2016/09/16 00:05:00 [error] 32594#0: *6673 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"
2016/09/16 00:05:19 [error] 32594#0: *6677 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: mail.l-system.cloud, request: "OPTIONS /cloud/remote.php/caldav/calendars/[email protected]/ HTTP/1.0", upstream: "fastcgi://unix:/var/run/php5-fpm.sock", host: "127.0.0.1"

the part log nginx

127.0.0.1 - [email protected] [15/Sep/2016:17:11:46 +0200] "PROPFIND /cloud/remote.php/carddav/addressbooks/[email protected]/contacts/ HTTP/1.1" 207 507 "-" "Z-Push CardDAV/0.6.c"
127.0.0.1 - [email protected] [15/Sep/2016:17:11:48 +0200] "PROPFIND /cloud/remote.php/carddav/addressbooks/[email protected]/contacts/ HTTP/1.1" 207 509 "-" "Z-Push CardDAV/0.6.c"
127.0.0.1 - [email protected] [15/Sep/2016:17:11:51 +0200] "PROPFIND /cloud/remote.php/carddav/addressbooks/[email protected]/contacts/ HTTP/1.1" 207 509 "-" "Z-Push CardDAV/0.6.c"
127.0.0.1 - [email protected] [15/Sep/2016:17:11:52 +0200] "PROPFIND /cloud/remote.php/carddav/addressbooks/[email protected]/contacts/ HTTP/1.1" 207 500 "-" "Z-Push CardDAV/0.6.c"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /caldav/calendars/[email protected]/personal/ HTTP/1.1" 207 577 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/personal/ HTTP/1.0" 207 565 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/personal/ HTTP/1.0" 207 565 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /caldav/calendars/[email protected]/personal/ HTTP/1.1" 207 577 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.1" 207 198 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.0" 207 187 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.1" 207 198 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.0" 207 187 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /caldav/calendars/[email protected]/personal/ HTTP/1.1" 207 577 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/personal/ HTTP/1.0" 207 565 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/personal/ HTTP/1.0" 207 565 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /caldav/calendars/[email protected]/personal/ HTTP/1.1" 207 577 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.1" 207 198 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:04 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.0" 207 187 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:05 +0200] "REPORT /caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.1" 207 198 "-" "ModifiedDAViCalClient"
127.0.0.1 - [email protected] [15/Sep/2016:17:12:05 +0200] "REPORT /cloud/remote.php/caldav/calendars/[email protected]/contact_birthdays/ HTTP/1.0" 207 187 "-" "ModifiedDAViCalClient"
@yodax
Copy link
Contributor

yodax commented Sep 18, 2016

Nginx is only acting as the proxy for the php5-fpm process. It seems that is crashing. What "usually" is the problem with z-push is that it doesn't understand some message in the store. This will result in errors.

z-push-admin -a list -u <email>

You can run the command above (via a ssh session) for a user and see if any errors are listed.

z-push-top

Will show active connections.

(This is the main reason why I gave up on using it)

@chalupal
Copy link
Author

chalupal commented Sep 18, 2016 •
edited
Loading

Hello yodax thanks for answer.

command result

-----------------------------------------------------
DeviceId:               224c6d7124be43638aaf13ebc79d3d46
Device type:            WindowsOutlook
UserAgent:              Outlook/16.0 (16.0.7167.6539; C2R; x86)
ActiveSync version:     14.0
First sync:             2016-09-13 16:36
Last sync:              2016-09-14 18:23
Total folders:          11
Synchronized folders:   10
Synchronized data:      Emails(5) Tasks(2) Calendars(2) Contacts
Status:                 Not available
WipeRequest on:         not set
WipeRequest by:         not set
Wiped on:               not set
Attention needed:       No errors known
-----------------------------------------------------
DeviceId:               androidc195792594
Device type:            Android
UserAgent:              Android/5.0.1-EAS-2.0
Device Model:           HUAWEI GRA-L09
Device IMEI:            866695021086319
Device friendly name:   HUAWEI GRA-L09
Device OS:              Android 5.0.1
Device Operator:        Vodafone CZ (23003)
ActiveSync version:     14.0
First sync:             2016-09-13 17:18
Last sync:              2016-09-18 08:48
Total folders:          11
Synchronized folders:   3
Synchronized data:      Emails(2) Contacts
Status:                 OK
WipeRequest on:         not set
WipeRequest by:         not set
Wiped on:               not set
Attention needed:       No errors known
-----------------------------------------------------
DeviceId:               28e438522a6041e19b699077624e7eb3
Device type:            WindowsOutlook
UserAgent:              Outlook/16.0 (16.0.7167.6539; C2R; x86)
ActiveSync version:     14.0
First sync:             2016-09-14 19:33
Last sync:              2016-09-14 23:37
Total folders:          12
Synchronized folders:   11
Synchronized data:      Emails(6) Tasks(2) Calendars(2) Contacts
Status:                 Not available
WipeRequest on:         not set
WipeRequest by:         not set
Wiped on:               not set
Attention needed:       No errors known
-----------------------------------------------------
DeviceId:               0fd0ee9180c74bd5bd30a25414ea6340
Device type:            WindowsOutlook
UserAgent:              Outlook/16.0 (16.0.7167.6539; C2R; x86)
ActiveSync version:     14.0
First sync:             2016-09-14 20:57
Last sync:              2016-09-18 08:37
Total folders:          12
Synchronized folders:   11
Synchronized data:      Emails(6) Tasks(2) Calendars(2) Contacts
Status:                 Not available
WipeRequest on:         not set
WipeRequest by:         not set
Wiped on:               not set
Attention needed:       No errors known

@chalupal chalupal reopened this Sep 18, 2016
@chalupal
Copy link
Author

chalupal commented Sep 18, 2016 •
edited
Loading 

PID   IP              USER    COMMAND TIME  AGENT               DEVID       Additional Information
12926 109.71.214.111  lukas.. Folde.. 01:06 Outlook/16.0 (16... 97a3a..1630 initializing
12479 109.71.214.111  stepa.. Folde.. 01:07 Outlook/16.0 (16... 0fd0e..6340 initializing
11910 80.95.123.130   lukas.. Ping    02:59 Outlook/16.0 (16... 5c66d..5e27 Sink 108/3540s on Email(5) Tasks(2) Calendar(2) Contacts
3598  46.135.47.4     stepa.. Ping    06:58 Android/5.0.1-EAS.. andro..2594 Sink 340/480s on Email Contacts
3449  46.135.47.4     stepa.. Ping    06:58 Android/5.0.1-EAS.. andro..2594 Sink 340/480s on Email Contacts
3442  46.135.36.254   lukas.. Ping    07:00 Android/6.0-EAS-2.0 andro..2949 Sink 336/780s on Email Contacts

And after 15 min. zero cennection

Z-Push top live statistics                                      18/09/2016 10:12:28
Open connections: 0                             Users:   0      Z-Push:   SVN-trunk-r1981
Push connections: 0                             Devices: 0      PHP-MAPI:
Action:                                         Hosts:   0

PID   IP              USER    COMMAND TIME  AGENT               DEVID       Additional Information

Colorscheme: Active  Open  Unknown  Terminated

@yodax
Copy link
Contributor

yodax commented Sep 18, 2016

Can you prevent the outlook clients from connecting? I never got that to work. Maybe it's those clients.

If that doesn't give a hint, you might want to raise an issue with the upstream project: https://github.com/fmbiete/Z-Push-contrib

Mail-in-a-box uses @fmbiete 's z-push library.

@chalupal
Copy link
Author

From z-push error log

18/09/2016 08:59:00 [ 3449] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error resyncing vcards: Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 08:59:00 [ 3449] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error getting the changes
18/09/2016 09:09:32 [ 3598] [ERROR] [[email protected]] BackendCardDAV->GetMessageList - Error getting the vcards in 'https://127.0.0.1:443/cloud/remote.php/carddav/addressbooks/[email protected]/contacts/': Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 09:09:32 [ 3598] [ERROR] [[email protected]] BackendCardDAV->GetMessageList - Error getting the vcards
18/09/2016 09:20:21 [ 3598] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error resyncing vcards: Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 09:20:21 [ 3598] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error getting the changes
18/09/2016 09:28:48 [19195] [ERROR] [[email protected]] BackendCardDAV->ChangesSinkInitialize - Error doing the initial sync for 'https://127.0.0.1:443/cloud/remote.php/carddav/addressbooks/[email protected]/contacts/': Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 09:38:49 [ 3242] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error resyncing vcards: Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 09:38:49 [ 3242] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error getting the changes
18/09/2016 09:38:49 [30174] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error resyncing vcards: Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 09:38:49 [30174] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error getting the changes
18/09/2016 09:48:49 [  441] [ERROR] [[email protected]] BackendCardDAV->GetMessageList - Error getting the vcards in 'https://127.0.0.1:443/cloud/remote.php/carddav/addressbooks/[email protected]/contacts/': Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 09:48:49 [  441] [ERROR] [[email protected]] BackendCardDAV->GetMessageList - Error getting the vcards
18/09/2016 09:48:50 [ 3442] [ERROR] [[email protected]] BackendCardDAV->GetMessageList - Error getting the vcards in 'https://127.0.0.1:443/cloud/remote.php/carddav/addressbooks/[email protected]/contacts/': Woops, something's gone wrong! The CardDAV server returned the http status code 504.
18/09/2016 09:48:50 [ 3442] [ERROR] [[email protected]] BackendCardDAV->GetMessageList - Error getting the vcards
18/09/2016 10:01:36 [ 3442] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error resyncing vcards: Woops, something's gone wrong! The CardDAV server returned the http status code 0.
18/09/2016 10:01:36 [ 3442] [ERROR] [[email protected]] BackendCardDAV->ChangesSink - Error getting the changes
18/09/2016 10:01:36 [ 3598] [ERROR] [[email protected]] BackendCardDAV->Logon(): User '[email protected]' failed to authenticate on 'https://127.0.0.1:443/carddav/addressbooks/[email protected]/': 
18/09/2016 10:01:36 [ 3449] [ERROR] [[email protected]] BackendCardDAV->Logon(): User '[email protected]' failed to authenticate on 'https://127.0.0.1:443/carddav/addressbooks/[email protected]/':

@yodax
Copy link
Contributor

yodax commented Sep 18, 2016 •
edited
Loading

Could you have the user view the contacts from the owncloud webpage? Maybe a contact contains "something weird". (Names and addresses are one of the more complicated areas of software development)

Might be that owncloud's preferred (sabre) dav client isn't working properly. Basically guessing now..

@chalupal
Copy link
Author

chalupal commented Sep 18, 2016 •
edited
Loading

Webpage contacts and claendar works. No erros. Users dont have any contacts or calendar item.

@yodax
Copy link
Contributor

yodax commented Sep 18, 2016

Hmm no contacts, but it does fail on the contacts. That is weird. Perhaps instruct the users to disable the contacts in their connection? It might still be better to ask a the GitHub repo that I mentioned. More experts over there.

@chalupal
Copy link
Author

I think its no possible disable contacts an calendar in outlook.
Posted ask on z-push repo.
Thanks

@chalupal chalupal mentioned this issue Sep 18, 2016
Open
@JoshData
Copy link
Member

JoshData commented Aug 3, 2017

Closing because it's been a while. Feel free to re-open.

@JoshData JoshData closed this as completed Aug 3, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@JoshData @yodax @chalupal