Syncroton doesn't work
Open, Needs TriagePublic

Description

When I try to connect I got error and email aren't downloaded.

tail -f /var/log/kolab-syncroton/errors.log

[23-Jan-2019 14:42:01 Europe/Berlin] PHP Warning:  fread(): Length parameter must be greater than 0 in /usr/share/kolab-syncroton/lib/ext/Syncroton/Server.php on line 348
[23-Jan-2019 14:42:58 Europe/Berlin] PHP Warning:  count(): Parameter must be an array or an object that implements Countable in /usr/share/roundcubemail/program/lib/Roundcube/rcube_imap_generic.php on line 1733
[23-Jan-2019 14:42:58 Europe/Berlin] PHP Warning:  count(): Parameter must be an array or an object that implements Countable in /usr/share/roundcubemail/program/lib/Roundcube/rcube_imap_generic.php on line 1733

tail -f /var/log/kolab-syncroton/console.log

[23-Jan-2019 13:47:37,442769 +0100]: [DEBUG] Syncroton_Server::handle::62 REQUEST METHOD: OPTIONS
[23-Jan-2019 13:47:37,528171 +0100]: [DEBUG] Syncroton_Server::handle::62 REQUEST METHOD: POST
[23-Jan-2019 13:47:37,528584 +0100]: [DEBUG] Syncroton_Server::_handlePost::104 REQUEST Array
(
    [protocolVersion] => 14.1
    [command] => Settings
    [deviceId] => 18abe539fe2ff9485a69ce474f7b4ae2
    [deviceType] => WindowsMail
    [policyKey] => 0
    [saveInSent] => 
    [collectionId] => 
    [itemId] => 
    [attachmentName] => 
    [acceptMultipart] => 
    [userAgent] => WindowsMail
    [contentType] => application/vnd.ms-sync
)

[23-Jan-2019 13:47:38,028105 +0100]: [DEBUG] Syncroton_Server::_handlePost::127 xml request:
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE AirSync PUBLIC "-//AIRSYNC//DTD AirSync//EN" "http://www.microsoft.com/">
<Settings xmlns="uri:Settings">
  <DeviceInformation>
    <Set>
      <Model>Windows Device</Model>
      <IMEI/>
      <FriendlyName>DESKTOP-OM6HI07</FriendlyName>
      <OS>Windows 10.0.16299</OS>
      <OSLanguage>Italian</OSLanguage>
      <PhoneNumber/>
      <UserAgent>MSFT-WIN-3/10.0.16299</UserAgent>
      <EnableOutboundSMS>0</EnableOutboundSMS>
      <MobileOperator>OperatorName</MobileOperator>
    </Set>
  </DeviceInformation>
  <UserInformation>
    <Get/>
  </UserInformation>
</Settings>

[23-Jan-2019 13:47:38,028362 +0100]: [DEBUG] Syncroton_Command_Wbxml::__construct::163 sync timestamp: 2019-01-23 13:47:38
[23-Jan-2019 13:47:38,041828 +0100]: [DEBUG] Syncroton_Server::_handlePost::177 xml response(0):
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE AirSync PUBLIC "-//AIRSYNC//DTD AirSync//EN" "http://www.microsoft.com/">
<Settings xmlns="uri:Settings" xmlns:Syncroton="uri:Syncroton" xmlns:Internal="uri:Internal">
  <Status>1</Status>
  <DeviceInformation>
    <Set>
      <Status>1</Status>
    </Set>
  </DeviceInformation>
  <UserInformation>
    <Status>1</Status>
    <Get>
      <Accounts>
        <Account>
          <UserDisplayName>Emanuele xxxxx</UserDisplayName>
          <EmailAddresses>
            <PrimarySmtpAddress>emanuelexxxxx@xxxx.xxx</PrimarySmtpAddress>
          </EmailAddresses>
        </Account>
      </Accounts>
    </Get>
  </UserInformation>
</Settings>

[23-Jan-2019 13:47:38,111204 +0100]: [DEBUG] Syncroton_Server::handle::62 REQUEST METHOD: POST
[23-Jan-2019 13:47:38,111905 +0100]: [DEBUG] Syncroton_Server::_handlePost::104 REQUEST Array
(
    [protocolVersion] => 14.1
    [command] => FolderSync
    [deviceId] => 18abe539fe2ff9485a69ce474f7b4ae2
    [deviceType] => WindowsMail
    [policyKey] => 0
    [saveInSent] => 
    [collectionId] => 
    [itemId] => 
    [attachmentName] => 
    [acceptMultipart] => 
    [userAgent] => WindowsMail
    [contentType] => application/vnd.ms-sync
)

[23-Jan-2019 13:47:38,545558 +0100]: [DEBUG] Syncroton_Server::_handlePost::127 xml request:
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE AirSync PUBLIC "-//AIRSYNC//DTD AirSync//EN" "http://www.microsoft.com/">
<FolderSync xmlns="uri:FolderHierarchy">
  <SyncKey>0</SyncKey>
</FolderSync>

[23-Jan-2019 13:47:38,545879 +0100]: [DEBUG] Syncroton_Command_Wbxml::__construct::163 sync timestamp: 2019-01-23 13:47:38
[23-Jan-2019 13:47:38,546075 +0100]: [DEBUG] Syncroton_Command_FolderSync::handle::80 synckey is 0
[23-Jan-2019 13:47:38,736315 +0100]: [DEBUG] Syncroton_Server::_handlePost::177 xml response(0):
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE AirSync PUBLIC "-//AIRSYNC//DTD AirSync//EN" "http://www.microsoft.com/">
<FolderSync xmlns="uri:FolderHierarchy" xmlns:Syncroton="uri:Syncroton" xmlns:Internal="uri:Internal">
  <Status>1</Status>
  <SyncKey>1</SyncKey>
  <Changes>
    <Count>8</Count>
    <Add>
      <ServerId>Calendar::Syncroton</ServerId>
      <ParentId>0</ParentId>
      <DisplayName>Calendar</DisplayName>
      <Type>8</Type>
    </Add>
    <Add>
      <ServerId>Contacts::Syncroton</ServerId>
      <ParentId>0</ParentId>
      <DisplayName>Contacts</DisplayName>
      <Type>9</Type>
    </Add>
    <Add>
      <DisplayName>Inbox</DisplayName>
      <ServerId>Inbox</ServerId>
      <ParentId>0</ParentId>
      <Type>2</Type>
    </Add>
    <Add>
      <DisplayName>Drafts</DisplayName>
      <ServerId>Drafts</ServerId>
      <ParentId>0</ParentId>
      <Type>3</Type>
    </Add>
    <Add>
      <DisplayName>Sent Items</DisplayName>
      <ServerId>Sent Items</ServerId>
      <ParentId>0</ParentId>
      <Type>5</Type>
    </Add>
    <Add>
      <DisplayName>Deleted Items</DisplayName>
      <ServerId>Deleted Items</ServerId>
      <ParentId>0</ParentId>
      <Type>4</Type>
    </Add>
    <Add>
      <ServerId>Notes::Syncroton</ServerId>
      <ParentId>0</ParentId>
      <DisplayName>Notes</DisplayName>
      <Type>10</Type>
    </Add>
    <Add>
      <ServerId>Tasks::Syncroton</ServerId>
      <ParentId>0</ParentId>
      <DisplayName>Tasks</DisplayName>
      <Type>7</Type>
    </Add>
  </Changes>
</FolderSync>

dpkg -l | grep kolab-

ii  kolab-cli                                   0.8.10-0~kolab2                              all          Command-line utilities for Kolab
ii  kolab-conf                                  0.8.10-0~kolab2                              all          Configuration management for Kolab
ii  kolab-freebusy                              1.1.1-0~kolab1                               all          Free/Busy for Kolab Groupware
ii  kolab-imap                                  16.0.1-13                                    all          IMAP server for Kolab Groupware server
ii  kolab-ldap                                  16.0.1-13                                    all          LDAP server for Kolab Groupware server
ii  kolab-mta                                   16.0.1-13                                    all          MTA server for Kolab Groupware server
ii  kolab-saslauthd                             0.8.10-0~kolab2                              all          SASL Authentication Daemon for Kolab
ii  kolab-schema                                3.3-0~kolab1                                 all          LDAP schema files for Kolab Groupware
ii  kolab-server                                0.8.10-0~kolab2                              all          Kolab Groupware Server
ii  kolab-syncroton                             2.3.14-0~kolab1                              all          ActiveSync for Kolab Groupware
ii  kolab-webadmin                              3.2.12-0~kolab1                              all          Kolab administration web interface
ii  kolab-webclient                             16.0.1-12                                    all          Webmail client for Kolab Groupware server
ii  kolab-xml                                   0.8.10-0~kolab2                              all          Kolab XML format wrapper for pykolab
ii  roundcubemail-plugin-kolab-activesync       1:3.4.2-0~kolab1                             all          kolab_activesync plugin for Roundcube
ii  roundcubemail-plugin-kolab-addressbook      1:3.4.2-0~kolab1                             all          kolab_addressbook plugin for Roundcube
ii  roundcubemail-plugin-kolab-auth             1:3.4.2-0~kolab1                             all          kolab_auth plugin for Roundcube
ii  roundcubemail-plugin-kolab-config           1:3.4.2-0~kolab1                             all          kolab_config plugin for Roundcube
ii  roundcubemail-plugin-kolab-delegation       1:3.4.2-0~kolab1                             all          kolab_delegation plugin for Roundcube
ii  roundcubemail-plugin-kolab-files            1:3.4.2-0~kolab1                             all          kolab_files plugin for Roundcube
ii  roundcubemail-plugin-kolab-folders          1:3.4.2-0~kolab1                             all          kolab_folders plugin for Roundcube
ii  roundcubemail-plugin-kolab-notes            1:3.4.2-0~kolab1                             all          kolab_notes plugin for Roundcube
ii  roundcubemail-plugin-kolab-tags             1:3.4.2-0~kolab1                             all          kolab_tags plugin for Roundcube

dpkg -l pykolab

Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name                                                          Version                             Architecture                        Description
+++-=============================================================-===================================-===================================-================================================================================================================================
ii  pykolab                                                       0.8.10-0~kolab2                     all                                 Kolab Groupware daemon and utilities

Details

Ticket Type
Task

These warnings does not look relevant, and the syncroton log looks normal. Could you provide imap_debug log? Do you see more requests from the client in http access/error log? I didn't try WindowsMail, but it looks like it just stopped after synchronizing folders hierarchy.

I've tried to enable imap_debug, tail it when I perform update from the client, but nothing is printing.

This is the access apache log when I perform client update.

192.168.9.148 - user@domain.tld [28/Jan/2019:15:54:49 +0100] "OPTIONS /Microsoft-Server-ActiveSync?User=user&DeviceId=18ABE539FE2FF9485A69CE474F7B4AE2&DeviceType=WindowsMail HTTP/1.1" 200 672 "-" "MSFT-WIN-3/10.0.17134"
192.168.9.148 - user@domain.tld [28/Jan/2019:15:54:49 +0100] "POST /Microsoft-Server-ActiveSync?jREQBBAYq+U5/i/5SFppzkdPe0riBAAAAAALV2luZG93c01haWw= HTTP/1.1" 200 359 "-" "-"
192.168.9.148 - user@domain.tld [28/Jan/2019:15:54:50 +0100] "POST /Microsoft-Server-ActiveSync?jQkQBBAYq+U5/i/5SFppzkdPe0riBAAAAAALV2luZG93c01haWw= HTTP/1.1" 200 919 "-" "-"