Randomly password request



  • Hi all,
    I have noticed a strange behaviour that occurs periodically in a random manner.
    The account configured on smartphone requests the credentials to the user after some period of time (randomly).
    When we activated the debug log with WBXML request, we noticed that the credentials are requested after some “Search” command.
    Z-push (version 2.4.1) is configured via custom back-end and our back-end does not implement ISearchProvider.
    Is ISearchProvider implementation mandatory when working with Calendar (no Tasks) and Contacts ?

    We noticed this with a Samsung Galaxy S9

    Thank you in advance
    Denis


  • Kopano

    Hi Denis,

    first of all, Z-Push 2.4.1 is quite old. You should upgrade to a recent version (currently Z-Push 2.5.1).

    If you want to provide search results, then yes, implementing ISearchProvider is necessary. Otherwise Z-Push will return server error for search results (which is probably happening in your case, without the logs it’s difficult to say that for sure).

    It’s possible to search for contacts, so it depends on you if you want to implement ISearchProvider backend and the GetGALSearchResults function in order to enable that functionality for the users.

    Manfred



  • Hi Manfred,
    thanks for your reply.
    I try to share the debug log with wbxml of the user.

    18/12/2019 02:36:40 [28149] [DEBUG] LoopDetection->IsSyncStateObsolete(): check folderid: 'calendar' uuid '6a62092c-dbd7-4d32-9214-c0c2a887a458' counter: 1000 - last counter: 999 with 0 queued
    18/12/2019 02:36:40 [28149] [DEBUG] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'calendar', returning as is.
    18/12/2019 02:36:40 [28149] [DEBUG] ExportChangesDiff->InitializeExporter(): Initializing message diff engine. '1898' messages in state
    18/12/2019 02:36:40 [28149] [DEBUG] custom_backend::GetMessageList(calendar,0)
    18/12/2019 02:36:45 [28149] [DEBUG] custom_backend::record count(1898)
    18/12/2019 02:36:45 [28149] [ INFO] ExportChangesDiff->InitializeExporter(): Found '0' changes for 'calendar'
    18/12/2019 02:37:15 [28149] [DEBUG] LoopDetection->IsSyncStateObsolete(): check folderid: 'calendar' uuid '6a62092c-dbd7-4d32-9214-c0c2a887a458' counter: 1000 - last counter: 999 with 0 queued
    18/12/2019 02:37:15 [28149] [DEBUG] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'calendar', returning as is.
    18/12/2019 02:37:15 [28149] [DEBUG] ExportChangesDiff->InitializeExporter(): Initializing message diff engine. '1898' messages in state
    18/12/2019 02:37:15 [28149] [DEBUG] custom_backend::GetMessageList(calendar,0)
    18/12/2019 02:37:22 [28149] [DEBUG] custom_backend::record count(1898)
    18/12/2019 02:37:22 [28149] [ INFO] ExportChangesDiff->InitializeExporter(): Found '0' changes for 'calendar'
    18/12/2019 02:37:52 [28149] [DEBUG] LoopDetection->IsSyncStateObsolete(): check folderid: 'calendar' uuid '6a62092c-dbd7-4d32-9214-c0c2a887a458' counter: 1000 - last counter: 999 with 0 queued
    18/12/2019 02:37:52 [28149] [DEBUG] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'calendar', returning as is.
    18/12/2019 02:37:52 [28149] [DEBUG] ExportChangesDiff->InitializeExporter(): Initializing message diff engine. '1898' messages in state
    18/12/2019 02:37:52 [28149] [DEBUG] custom_backend::GetMessageList(calendar,0)
    18/12/2019 02:37:59 [28149] [DEBUG] custom_backend::record count(1898)
    18/12/2019 02:37:59 [28149] [ INFO] ExportChangesDiff->InitializeExporter(): Found '0' changes for 'calendar'
    18/12/2019 02:38:09 [28149] [DEBUG] SyncCollections->CheckForChanges(): no changes found after 547s
    18/12/2019 02:38:09 [28149] [DEBUG] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
    18/12/2019 02:38:09 [28149] [WBXML] O  <Ping:Ping>
    18/12/2019 02:38:09 [28149] [WBXML] O   <Ping:Status>
    18/12/2019 02:38:09 [28149] [WBXML] O   1
    18/12/2019 02:38:09 [28149] [WBXML] O   </Ping:Status>
    18/12/2019 02:38:09 [28149] [WBXML] O  </Ping:Ping>
    18/12/2019 02:38:09 [28149] [DEBUG] WBXMLEncoder->endTag() WBXML output completed
    18/12/2019 02:38:09 [28149] [WBXML] WBXML-OUT: AwFqAAANRUcDMQABAQ==
    18/12/2019 02:38:09 [28149] [WBXML] WBXML-IN : AwFqAAANRUlKSwNjYWxlbmRhcgABTANDYWxlbmRhcgABAQEB
    18/12/2019 02:38:09 [28149] [DEBUG] LoopDetection->ProcessLoopDetectionTerminate()
    18/12/2019 02:38:09 [28149] [ INFO] cmd='Ping' memory='9.73 MiB/10.00 MiB' time='549.43s' devType='SamsungDevice' devId='sec10601dfd2842b' getUser='username' from='IP' idle='530s' version='2.4.1-1' method='POST' httpcode='200'
    18/12/2019 02:38:09 [28149] [DEBUG] -------- End
    18/12/2019 10:11:58 [13842] [DEBUG] -------- Start
    18/12/2019 10:11:58 [13842] [DEBUG] cmd='ResolveRecipients' devType='SamsungDevice' devId='sec10601dfd2842b' getUser='username' from='IP' version='2.4.1-1' method='POST'
    18/12/2019 10:11:58 [13842] [DEBUG] Used timezone 'Europe/Rome'
    18/12/2019 10:11:58 [13842] [DEBUG] Request::ProcessHeaders() ASVersion: 14.1
    18/12/2019 10:11:58 [13842] [DEBUG] ZPush::CommandNeedsProvisioning(21): true
    18/12/2019 10:11:58 [13842] [DEBUG] FileStateMachine->GetState() read '4067' bytes from file: '/zpushPATH/state/b/2/sec10601dfd2842b-devicedata'
    18/12/2019 10:11:58 [13842] [DEBUG] ASDevice data loaded for user: 'username'
    18/12/2019 10:11:58 [13842] [DEBUG] TopCollector(): Initialized mutexid Resource id #14 and memid Resource id #15.
    18/12/2019 10:11:58 [13842] [DEBUG] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
    18/12/2019 10:11:58 [13842] [DEBUG] LoopDetection(): Initialized mutexid Resource id #17 and memid Resource id #18.
    18/12/2019 10:11:58 [13842] [DEBUG] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
    18/12/2019 10:11:58 [13842] [DEBUG] ZPush::HierarchyCommand(21): false
    18/12/2019 10:11:58 [13842] [DEBUG] DeviceManager->ProvisioningRequired('471884119') saved device key '471884119': false
    18/12/2019 10:11:58 [13842] [DEBUG] DeviceManager->getPolicyName(): determined policy name: 'default'
    18/12/2019 10:11:58 [13842] [DEBUG] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
    18/12/2019 10:11:58 [13842] [DEBUG] ZPush::CommandNeedsAuthentication(21): true
    18/12/2019 10:11:58 [13842] [DEBUG] custom_backend::Logon(username,,password)
    18/12/2019 10:11:58 [13842] [DEBUG] custom_backend::Logon -> Succesfull !
    18/12/2019 10:11:58 [13842] [DEBUG] ZPush::CommandNeedsPlainInput(21): false
    18/12/2019 10:11:58 [13842] [WBXML] I  <ResolveRecipients:ResolveRecipients>
    18/12/2019 10:11:58 [13842] [WBXML] I   <ResolveRecipients:To>
    18/12/2019 10:11:58 [13842] [WBXML] I    user_email
    18/12/2019 10:11:58 [13842] [WBXML] I   </ResolveRecipients:To>
    18/12/2019 10:11:58 [13842] [WBXML] I   <ResolveRecipients:Options>
    18/12/2019 10:11:58 [13842] [WBXML] I    <ResolveRecipients:Picture>
    18/12/2019 10:11:58 [13842] [WBXML] I     <ResolveRecipients:MaxPictures>
    18/12/2019 10:11:58 [13842] [WBXML] I      1
    18/12/2019 10:11:58 [13842] [WBXML] I     </ResolveRecipients:MaxPictures>
    18/12/2019 10:11:58 [13842] [WBXML] I    </ResolveRecipients:Picture>
    18/12/2019 10:11:58 [13842] [WBXML] I   </ResolveRecipients:Options>
    18/12/2019 10:11:58 [13842] [WBXML] I  </ResolveRecipients:ResolveRecipients>
    18/12/2019 10:11:58 [13842] [DEBUG] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
    18/12/2019 10:11:58 [13842] [WBXML] O  <ResolveRecipients:ResolveRecipients>
    18/12/2019 10:11:58 [13842] [WBXML] O   <ResolveRecipients:Status>
    18/12/2019 10:11:58 [13842] [WBXML] O   5
    18/12/2019 10:11:58 [13842] [WBXML] O   </ResolveRecipients:Status>
    18/12/2019 10:11:58 [13842] [WBXML] O  </ResolveRecipients:ResolveRecipients>
    18/12/2019 10:11:58 [13842] [DEBUG] WBXMLEncoder->endTag() WBXML output completed
    18/12/2019 10:11:58 [13842] [WBXML] WBXML-OUT: AwFqAAAKRUcDNQABAQ==
    18/12/2019 10:11:58 [13842] [WBXML] WBXML-IN : AwFqAAAKRVADbXZAbXYuaXQAAU9aXQMxAAEBAQE=
    18/12/2019 10:11:58 [13842] [DEBUG] LoopDetection->ProcessLoopDetectionTerminate()
    18/12/2019 10:11:58 [13842] [ INFO] cmd='ResolveRecipients' memory='4.83 MiB/5.25 MiB' time='1.46s' devType='SamsungDevice' devId='sec10601dfd2842b' getUser='username' from='IP' idle='0s' version='2.4.1-1' method='POST' httpcode='200'
    18/12/2019 10:11:58 [13842] [DEBUG] -------- End
    

    (I have changed the real username-ip)
    As you can see, there are any activities till 10 AM from 2.
    I don’t understand why ResolveRecipients cmd is sent by the device…usually is sent after 2-3 search cmd and I was thinking about search issues but now is prompted to the user with no apparently issue.



  • Any help ?


  • Kopano

    Hi @denisdal,

    @denisdal said in Randomly password request:

    Any help ?

    did you update to Z-Push 2.5.1 like I suggested?

    ResolveRecipients didn’t return a success code, so you should look into that.

    Manfred



  • Hi @Manfred finally I was able to update zpush to latest version.
    Unfortunately, same behaviour …


  • Kopano

    Hi @denisdal,

    @denisdal said in Randomly password request:

    Hi @Manfred finally I was able to update zpush to latest version.
    Unfortunately, same behaviour …

    Did you also check why ResolveRecipients didn’t return a success code like I suggested?

    Manfred



  • @Manfred said in Randomly password request:

    ResolveRecipients

    Hi Manfred, my backend doesn’t have ResolveRecipients function.
    In this case, is ok take the function as example in caldav backend ? (Simply return an empty array)
    Or, as I can see in kopano backend, return a SyncResolveRecipients object with a protocol error status ?

    My goal is to keep sync running, as backend does not support a resolve engine.

    Thank you


  • Kopano

    Hi @denisdal,

    @denisdal said in Randomly password request:

    Hi Manfred, my backend doesn’t have ResolveRecipients function.
    In this case, is ok take the function as example in caldav backend ? (Simply return an empty array)

    Yeah, you could try that.

    Or, as I can see in kopano backend, return a SyncResolveRecipients object with a protocol error status ?

    Kopano backend only returns protocol error in a certain error case. It does a proper resolving.

    If you don’t have you own ResolveRecipients it will fall back to the default Backend class function which returns protocol error which is the case you have now.

    ResolveRecipients was just a guess because it was in the log excerpt you posted. In the initial post you mentioned that the password requests happened after Search command, however you haven’t posted any logs which contain Search request.

    Manfred


Log in to reply