Closed chises closed 9 years ago
Loguserfile relies on the user being authenticated, seems like your issue happens prior or during authentication
Hi @chises
In your case you should yet see 2 log lines before the error:
03/04/2015 09:56:23 [ 7436] [DEBUG] [fmbiete] [android1416133468152] -------- Start
03/04/2015 09:56:23 [ 7436] [ INFO] [fmbiete] [android1416133468152] Version='SVN-trunk-r1931' method='POST' from='10.1.96.253' cmd='Sync' getUser='fmbiete'
The interesting one is the second. You will see method=POST, but what's the value for cmd, getUser and the 2 values after [INFO]??
Actually i am on vacation. I will come back with More Information in about 2 days :)
hi, sorry for the late Response: still same error: outlook2013 ok, Windows phone 8.1 - error:
DEBUG LOG: 12/04/2015 13:09:02 [ 6278] [ INFO] [email@tld.de] User-agent: 'unknown' 12/04/2015 13:09:02 [ 6278] [DEBUG] [email@tld.de] ZPush::PrintZPushLegal() 12/04/2015 13:09:02 [ 6278] [DEBUG] [email@tld.de] -------- End 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] -------- Start 12/04/2015 13:09:02 [ 8299] [ INFO] [email@tld.de] Version='SVN-trunk-r1935' method='GET' from='87.145.15.243' cmd='' getUser='email@tld.de' devId='' devType='' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Used timezone 'Europe/Berlin' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Including backend file: '/var/www/Z-Push-contrib/backend/combined/combined.php' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Including backend file: '/var/www/Z-Push-contrib/backend/imap/imap.php' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Including backend file: '/var/www/Z-Push-contrib/backend/caldav/caldav.php' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Including backend file: '/var/www/Z-Push-contrib/backend/carddav/carddav.php' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Combined 3 backends loaded. 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] SqlStateMachine(): init 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] SqlStateMachine->GetStateVersion() 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Request::ProcessHeaders() ASVersion: 14.1 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] ZPush::CommandNeedsAuthentication(0): true 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Combined->Logon('email@tld.de', '',***)) 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] BackendIMAP->Logon(): User 'email@tld.de' is authenticated on '{localhost:993/imap/ssl/novalidate-cert}' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] BackendCalDAV->Logon(): User 'email@tld.de' is authenticated on CalDAV 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] BackendCardDAV->Logon(): User 'email@tld.de' is authenticated on 'https://tld.de:443/owncloud/remote.php/carddav/addressbooks/email@tld.de/' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] BackendCardDAV::discoverAddressbooks() Found addressbook 'https://tld.de:443/owncloud/remote.php/carddav/addressbooks/email@tld.de/kontakte/' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Combined->Logon() success 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Combined->Setup('email@tld.de', 'true', '') 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] Combined->Setup() success 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] NoPostRequestException: This is the Z-Push location and can only be accessed by Microsoft ActiveSync-capable devices - code: 2 - file: /var/www/Z-Push-contrib/index.php:196 12/04/2015 13:09:02 [ 8299] [ INFO] [email@tld.de] User-agent: 'unknown' 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] ZPush::PrintZPushLegal() 12/04/2015 13:09:02 [ 8299] [DEBUG] [email@tld.de] -------- End
Ummm... indeed that's wrong. The phone is sending a GET request, and that's a bad request.
Try to remove and readd the account. I don't have a Windows Phone 8.1 so it will be hard to debug.
Update: i wiped and remove all devices and users: still same issue, here my webserver logs 87.185.254.197 = Client ip 88.198.206.154 = Server ip
87.185.254.197 - user@tld.de [18/Apr/2015:08:03:13 +0200] "OPTIONS /Microsoft-Server-ActiveSync?User=michael.weber&DeviceId=2FE7A28D04CA5D3C7422E3C2AD95DA16&DeviceType=WP8 HTTP/1.1" 301 184 "-" "MSFT-WP/8.10.14219" "-" 87.185.254.197 - user@tld.de [18/Apr/2015:08:03:13 +0200] "OPTIONS /Microsoft-Server-ActiveSync?User=michael.weber&DeviceId=2FE7A28D04CA5D3C7422E3C2AD95DA16&DeviceType=WP8 HTTP/1.1" 200 5 "-" "MSFT-WP/8.10.14219" "-" 87.185.254.197 - user@tld.de [18/Apr/2015:08:03:13 +0200] "POST /Microsoft-Server-ActiveSync?jBEHBBAv56KNBMpdPHQi48KtldoWBAAAAAADV1A4 HTTP/1.1" 301 184 "-" "-" "-" 88.198.206.154 - - [18/Apr/2015:08:03:13 +0200] "OPTIONS /owncloud/remote.php/caldav/calendars/user@tld.de/ HTTP/1.1" 401 304 "-" "ModifiedDAViCalClient" "-" 88.198.206.154 - user@tld.de [18/Apr/2015:08:03:13 +0200] "OPTIONS /owncloud/remote.php/caldav/calendars/user@tld.de/ HTTP/1.1" 200 0 "-" "ModifiedDAViCalClient" "-" 88.198.206.154 - - [18/Apr/2015:08:03:13 +0200] "OPTIONS /owncloud/remote.php/carddav/addressbooks/user@tld.de/ HTTP/1.1" 401 304 "-" "Z-Push CardDAV/0.6.c" "-" 88.198.206.154 - user@tld.de [18/Apr/2015:08:03:13 +0200] "OPTIONS /owncloud/remote.php/carddav/addressbooks/user@tld.de/ HTTP/1.1" 200 0 "-" "Z-Push CardDAV/0.6.c" "-" 88.198.206.154 - user@tld.de [18/Apr/2015:08:03:14 +0200] "PROPFIND /owncloud/remote.php/carddav/addressbooks/user@tld.de/ HTTP/1.1" 207 743 "-" "Z-Push CardDAV/0.6.c" "-" 87.185.254.197 - user@tld.de [18/Apr/2015:08:03:14 +0200] "GET /Microsoft-Server-ActiveSync?jBEHBBAv56KNBMpdPHQi48KtldoWBAAAAAADV1A4 HTTP/1.1" 200 952 "-" "-" "-" 87.185.254.197 - user@tld.de [18/Apr/2015:08:03:14 +0200] "POST /Microsoft-Server-ActiveSync?jAkHBBAv56KNBMpdPHQi48KtldoWBAAAAAADV1A4 HTTP/1.1" 301 184 "-" "-" "-" 88.198.206.154 - - [18/Apr/2015:08:03:14 +0200] "OPTIONS /owncloud/remote.php/caldav/calendars/user@tld.de/ HTTP/1.1" 401 304 "-" "ModifiedDAViCalClient" "-" 88.198.206.154 - user@tld.de [18/Apr/2015:08:03:14 +0200] "OPTIONS /owncloud/remote.php/caldav/calendars/user@tld.de/ HTTP/1.1" 200 0 "-" "ModifiedDAViCalClient" "-" 88.198.206.154 - - [18/Apr/2015:08:03:14 +0200] "OPTIONS /owncloud/remote.php/carddav/addressbooks/user@tld.de/ HTTP/1.1" 401 304 "-" "Z-Push CardDAV/0.6.c" "-" 88.198.206.154 - user@tld.de [18/Apr/2015:08:03:14 +0200] "OPTIONS /owncloud/remote.php/carddav/addressbooks/user@tld.de/ HTTP/1.1" 200 0 "-" "Z-Push CardDAV/0.6.c" "-" 88.198.206.154 - user@tld.de [18/Apr/2015:08:03:14 +0200] "PROPFIND /owncloud/remote.php/carddav/addressbooks/user@tld.de/ HTTP/1.1" 207 743 "-" "Z-Push CardDAV/0.6.c" "-" 87.185.254.197 - user@tld.de [18/Apr/2015:08:03:14 +0200] "GET /Microsoft-Server-ActiveSync?jAkHBBAv56KNBMpdPHQi48KtldoWBAAAAAADV1A4 HTTP/1.1" 200 952 "-" "-" "-"
And the last GET is again that takes my attention... Maybe Microsoft changed something in Windows Phone 8.1.
It already worked with my wp 8.1 i tried a factory & hard reset. I tried a other email account. I tried to sync "no Content" (no email, no calendar, no Tasks) and i tried with email enabled. Still same issue :-( i habe no idea anymore..
Nothing changed.
Update: I installed WP 10 Preview on my device and had the same error: my phone told me about some Troubles and i could repair the active sync account and now it is working. Logs:
07/05/2015 14:32:47 [ 2201] [INFO] [user] Version='SVN-trunk-r1935' method='OPTIONS' from='80.187.110.108' cmd='' getUser='user' devId='2fe7a28d04ca5d3c7422e3c2ad95da16' devType='WP' 07/05/2015 14:32:47 [ 2201] [INFO] [user] Options request 07/05/2015 14:32:48 [ 2201] [INFO] [user@tld.de] Version='SVN-trunk-r1935' method='POST' from='80.187.110.108' cmd='Settings' getUser='user@tld.de' devId='2fe7a28d04ca5d3c7422e3c2ad95da16' devType='WP' 07/05/2015 14:32:48 [ 2201] [INFO] [user@tld.de] ProvisioningRequiredException: Retry after sending a PROVISION command - code: 0 - file: /var/www/Z-Push-contrib/index.php:188 07/05/2015 14:32:48 [ 2201] [INFO] [user@tld.de] User-agent: 'unknown' 07/05/2015 14:32:48 [ 2201] [INFO] [user@tld.de] Version='SVN-trunk-r1935' method='POST' from='80.187.110.108' cmd='Provision' getUser='user@tld.de' devId='2fe7a28d04ca5d3c7422e3c2ad95da16' devType='WP' 07/05/2015 14:32:48 [ 2201] [INFO] [user@tld.de] StateNotFoundException: FileStateMachine->GetStateHash(): Could not locate state '/var/lib/z-push/6/1/2fe7a28d04ca5d3c7422e3c2ad95da16-devicedata' - code: 0 - file: /var/www/Z-Push-contrib/lib/default/filestatemachine.php:106 07/05/2015 14:32:48 [ 2201] [INFO] [user@tld.de] Announcing latest AS version to device: 2.5,12.0,12.1,14.0 07/05/2015 14:32:48 [ 2201] [INFO] [user@tld.de] Linking device ID '2fe7a28d04ca5d3c7422e3c2ad95da16' to user 'user@tld.de' 07/05/2015 14:32:50 [ 2201] [INFO] [user@tld.de] Version='SVN-trunk-r1935' method='POST' from='80.187.110.108' cmd='Provision' getUser='user@tld.de' devId='2fe7a28d04ca5d3c7422e3c2ad95da16' devType='WP' 07/05/2015 14:32:50 [ 2201] [INFO] [user@tld.de] Version='SVN-trunk-r1935' method='POST' from='80.187.110.108' cmd='Settings' getUser='user@tld.de' devId='2fe7a28d04ca5d3c7422e3c2ad95da16' devType='WP' 07/05/2015 14:32:51 [ 2201] [INFO] [user@tld.de] Version='SVN-trunk-r1935' method='POST' from='80.187.110.108' cmd='FolderSync' getUser='user@tld.de' devId='2fe7a28d04ca5d3c7422e3c2ad95da16' devType='WP' 07/05/2015 14:32:51 [ 2201] [INFO] [user@tld.de] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/6/1/2fe7a28d04ca5d3c7422e3c2ad95da16-bs-1431001968' - code: 0 - file: /var/www/Z-Push-contrib/lib/default/filestatemachine.php:138 07/05/2015 14:32:51 [ 2201] [WARN] [user@tld.de] BackendIMAP->getFolderIdFromImapId('INBOX') = not initialized!
unbelievable!
Additional Update: it does not work with nginx webserver. Apache is required.. Actually i handle the ActiveSync request by Apache and Apache will use nginx for caldav,carddav request. If ginx will handle ActiveSync requests it is not working.
Can someone provide me a working nginx config for z-push. Current Folder Setup: root: /var/WWW/ zpush Folder: /var/WWW/z-push
In the docker folder you have a working config for php-fpm and nginx:
https://github.com/fmbiete/Z-Push-contrib/blob/master/docker/nginx/nginx.conf
/etc/php.ini
include_path=.:/usr/share/pear:/usr/share/php:/usr/local/src/awl.git/inc
max_execution_time = 900
max_input_time = 300
post_max_size = 20M
upload_max_filesize = 20M
I have reopened this, so if you can test again with the nginx config, please let us know.
ok so i retested it with nginx as webserver. i had to delete my account on the Windows phone and after that it is working. i cant believe it!
I am using z-push with imap and owncloud backend (owncloud for caldav+carddav) unfortunally i am unable to upload Textfile to provide my current nginx configuration.
So last update: it is working ;) thank you!
i already (before a few months) synced my phone successful. Outlook 2013 is working.
Setup: nginx version: nginx/1.6.2, PHP 5.4.39-0+deb7u1, BackendCombined After Setting up the Acount it can not be synced, WindowsPhone ErrorCode: 85010014
z-push error-Log: 01/04/2015 06:58:33 [28781] [FATAL] [user@tld.de] FatalException: Requested the Z-Push URL without the required GET parameters - code: 0 - file: /var/www/Z-Push-contrib/index.php:162
i cant see any log entries. even in Loguserfile with LOGLEVEL_DEVICEID. not even 1 entry.
nginx config:
server { listen 443 ssl spdy; server_name tld.de; ssl_certificate /etc/ssl/certs/cert.ssl.combine.crt; ssl_certificate_key /etc/ssl/private/cert.ssl.key; root /var/www; index index.php; fastcgibuffers 64 4K; rewrite (?i)^/Microsoft-Server-ActiveSync?(.)$ /z-push/index.php?$1; rewrite (?i)^/autodiscover/autodiscover.xml?(._)$ /z-push/autodiscover/autodiscover.php?$1; location = /robots.txt { allow all; log_not_found off; access_log off; }
}
Any ideas?