Moving emails from Inbox in Outlook brings them back during the resync

fbartels

@Realshadow said in Moving emails from Inbox in Outlook brings them back during the resync:

P.S. Is anyone interested in instructions how to deploy z-push on nextcloud? I have a veeeeeery detailed instruction I could share.

I am sure other Nextcloud users would appreciate this.

@Realshadow said in Moving emails from Inbox in Outlook brings them back during the resync:

the emails are moved but are resynchronized and show back up in my inbox after a second or two.

Did I get it right that you move mails (so more than one at a time) out of a folder into a different folder, the email seems to be moved initially but then reappears at its original location (essentially duplicating it)?

I am not familiar with the imap backend (I guess you are using it, since you were talking about nextcloud), but at least with the Kopano backend I have not yet heard of such a behaviour. Could you generate a wbxml logging of such a process?

Realshadow

Hello @fbartels

@fbartels said in Moving emails from Inbox in Outlook brings them back during the resync:

Did I get it right that you move mails (so more than one at a time) out of a folder into a different folder, the email seems to be moved initially but then reappears at its original location (essentially duplicating it)?

Correct, I am moving several emails from the Inbox, which is hosted on the server to a folder on a PST/Archive which is not on the server. In my previous installation mentioned in my original post, the mail was moved and automatically deleted from the inbox and was only available on the archive after. Once moved the resync duplicates the email.

@fbartels said in Moving emails from Inbox in Outlook brings them back during the resync:

I am not familiar with the imap backend (I guess you are using it, since you were talking about nextcloud), but at least with the Kopano backend I have not yet heard of such a behaviour. Could you generate a wbxml logging of such a process?

I have to create the log later tonight as I do not have access to my Outlook until I am at home from work. I will post these details later.

Thanks.

regards
realshadow

fbartels

@Realshadow said in Moving emails from Inbox in Outlook brings them back during the resync:

I am moving several emails from the Inbox, which is hosted on the server to a folder on a PST/Archive which is not on the server.

actually you should here already get a message that Outlook blocks moving the message. In Outlook you cannot move message out of or into activesync accounts.

I first thought that you were talking about moving the message between folders in the same account.

Realshadow

@fbartels said in Moving emails from Inbox in Outlook brings them back during the resync:

@Realshadow said in Moving emails from Inbox in Outlook brings them back during the resync:

I am moving several emails from the Inbox, which is hosted on the server to a folder on a PST/Archive which is not on the server.

actually you should here already get a message that Outlook blocks moving the message. In Outlook you cannot move message out of or into activesync accounts.

I first thought that you were talking about moving the message between folders in the same account.

I am not moving them INTO but OUT OF the active sync account. I indeed get the error message if I try to move items into the active sync account.

fbartels

@Realshadow ah right. my mistake. out of the account works (we had to disable this for the “kopano folder” created by KOE because users complained that they cannot move them back after moving messages there).

Just checked on my system and if I move a message out, it does not come back.

Realshadow

@fbartels could there be a setting I overlooked? As I am not using Kopano I am wondering if Kopano or previously Zarafa have a build in logic that deletes the email from the inbox on the IMAP server.

fbartels

@Realshadow Like I said I am not familiar with the IMAP backend, but scrolling through the config file does not make it seem like there is a setting for this.

Realshadow

@fbartels said in Moving emails from Inbox in Outlook brings them back during the resync:

@Realshadow Like I said I am not familiar with the IMAP backend, but scrolling through the config file does not make it seem like there is a setting for this.

Was afraid of your answer. I will do a WBXML and post it later tonight. Maybe we can identify something there.

Realshadow

@fbartels I just extracted the WBXML. I highlighted 2 rows in which I think the issue is located. look for the standard HTML comments . Again thanks for your help. Really appreciate that.

31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] -------- Start
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] cmd='Sync' devType='WindowsOutlook' devId='385887be32ed4f32adb177b4005e1fc4' getUser='BENUTZER' from='192.168.1.42' version='2.5.0+0-0' method='POST'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Used timezone 'America/Edmonton'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Including backend file: '/usr/share/z-push/backend/imap/imap.php'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Including backend file: '/usr/share/z-push/backend/caldav/caldav.php'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Including backend file: '/usr/share/z-push/backend/carddav/carddav.php'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined 3 backends loaded.
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Request::ProcessHeaders() ASVersion: 14.0
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ZPush::CommandNeedsProvisioning(0): true
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->GetState() read '2549' bytes from file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-devicedata'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ASDevice data loaded for user: 'BENUTZER'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] TopCollector(): Initialized mutexid Resource id #22 and memid Resource id #23.
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] LoopDetection(): Initialized mutexid Resource id #26 and memid Resource id #27.
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ZPush::HierarchyCommand(0): false
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] DeviceManager->ProvisioningRequired('0') saved device key '-1': false
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] DeviceManager->getPolicyName(): determined policy name: 'default'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] DeviceManager->getProvisioningPolicies(): loaded 'default' policy.
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ZPush::CommandNeedsAuthentication(0): true
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined->Logon('BENUTZER', '',***))
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->Logon(): User 'BENUTZER' is authenticated on '{localhost:143/imap/notls/norsh}'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendCalDAV->Logon(): User 'BENUTZER' is authenticated on CalDAV 'https://localhost:443/nextcloud/remote.php/dav/calendars/BENUTZER/'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendCardDAV->Logon(): User 'BENUTZER' is authenticated on 'https://localhost:443/nextcloud/remote.php/dav/addressbooks/users/BENUTZER/contacts/'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendCardDAV::discoverAddressbooks() Found addressbook 'https://localhost:443/nextcloud/remote.php/dav/addressbooks/users/BENUTZER/contacts/'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined->Logon() success
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ZPush::CommandNeedsPlainInput(0): false
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I  <Synchronize>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I   <Folders>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I    <Folder>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     <SyncKey>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      {c09b49fd-6014-4765-b002-fd883563e22a}188
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     </SyncKey>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     <FolderId>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      i/f5abaedb
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     </FolderId>
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->GetState() read '956' bytes from file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-c09b49fd-6014-4765-b002-fd883563e22a-fd'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] SyncParameters->UseCPO('DEFAULT')
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'i/f5abaedb', returning as is.
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] SyncCollections->AddCollection(): Folder id 'i/f5abaedb' : ref. PolicyKey '-1', ref. Lifetime '3540', last sync at '1564625291'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] SyncCollections->AddCollection(): Updated reference PolicyKey '-1', reference Lifetime '3540', Last sync at '1564625291'
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     <DeletesAsMoves>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      0
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     </DeletesAsMoves>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     <GetChanges>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      0
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     </GetChanges>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     <WindowSize>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      512
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     </WindowSize>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     <Options>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      <FilterType>
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] SyncParameters->UseCPO('DEFAULT')
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       0
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      </FilterType>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      <MIMESupport>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       2
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      </MIMESupport>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      <MIMETruncation>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       8
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      </MIMETruncation>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      <AirSyncBase:BodyPreference>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       <AirSyncBase:Type>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I        4
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       </AirSyncBase:Type>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       <AirSyncBase:AllOrNone>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I        1
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       </AirSyncBase:AllOrNone>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      </AirSyncBase:BodyPreference>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     </Options>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     <Perform>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      <Remove>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       <ServerEntryId>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I        479
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I       </ServerEntryId>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I      </Remove>
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Sync->getImporter(): initialize importer
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Sync->loadStates(): loading states for folder 'i/f5abaedb'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->GetState() read '2885' bytes from file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-c09b49fd-6014-4765-b002-fd883563e22a-188'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->CleanStates(): Deleting file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-c09b49fd-6014-4765-b002-fd883563e22a-fs-186'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ZPush::GetAdditionalSyncFolderStore('i/f5abaedb'): 'false'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined->Setup('', 'false', '', 'false')
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined->Setup() success
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined->GetImporter() Content: ImportChangesCombined:('i/f5abaedb')
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->SetMoveStates()
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->SetMoveStates() success
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->Config(...)
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->Config() success
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->ConfigContentParameters()
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->ConfigContentParameters() success
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] LoopDetection->SetSyncStateUsage(): uuid: c09b49fd-6014-4765-b002-fd883563e22a  counter: 188
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->StatMessage('f5abaedb','479')
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->GetState() read '833' bytes from file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-bs-1563743265'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->getImapIdFromFolderId('f5abaedb') = INBOX
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->DeleteMessage('f5abaedb','479')
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->getImapIdFromFolderId('f5abaedb') = INBOX
<!-- I THINK HERE IS WHERE THE ISSUE STARTS -->
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->DeleteMessage('f5abaedb','479') move message to trash folder
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->MoveMessage('f5abaedb','479','TRASH')
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->getImapIdFromFolderId('f5abaedb') = INBOX
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->getImapIdFromFolderId('TRASH') = not found
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->imap_inside_cutoffdate(): Checking if the messages is withing the cutoffdate 0, 479
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->imap_inside_cutoffdate(): No cutoffdate, all the messages are in range
31/07/2019 20:10:33 [ 4922] [ INFO] [BENUTZER] StatusException: BackendIMAP->MoveMessage('f5abaedb','479','TRASH'): Error, copy to destination folder failed: [CANNOT] Invalid mailbox name: Name is empty (0.000 + 0.000 secs). - code: 5 - file: /usr/share/z-push/backend/imap/imap.php:1624
<!-- HERE THE MESSAGE IS RESYNCHRONIZED -->
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Sync->importMessage(): message imported
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I     </Perform>
31/07/2019 20:10:33 [ 4922] [ INFO] [BENUTZER] Processed '1' incoming changes
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->SetState() written 2987 bytes on file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-c09b49fd-6014-4765-b002-fd883563e22a-fs-188'
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I    </Folder>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I   </Folders>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] I  </Synchronize>
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] HandleSync(): Start Output
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Folder type: Email
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O  <Synchronize>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O   <Folders>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O    <Folder>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     <SyncKey>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     {c09b49fd-6014-4765-b002-fd883563e22a}189
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     </SyncKey>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     <FolderId>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     i/f5abaedb
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     </FolderId>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     <Status>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     1
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     </Status>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     <Replies>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O      <Remove>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O       <ServerEntryId>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O       479
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O       </ServerEntryId>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O       <Status>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O       8
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O       </Status>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O      </Remove>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O     </Replies>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O    </Folder>
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->SetState() written 2805 bytes on file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-c09b49fd-6014-4765-b002-fd883563e22a-189'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] SyncCollections->SaveCollection(): Data of folder 'i/f5abaedb' changed
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->SetState() written 985 bytes on file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-c09b49fd-6014-4765-b002-fd883563e22a-fd'
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O   </Folders>
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] O  </Synchronize>
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] WBXMLEncoder->endTag() WBXML output completed
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] WBXML-OUT: AwFqAEVcT0sDe2MwOWI0OWZkLTYwMTQtNDc2NS1iMDAyLWZkODgzNTYzZTIyYX0xODkAAVIDaS9mNWFiYWVkYgABTgMxAAFGSU0DNDc5AAFOAzgAAQEBAQEB
31/07/2019 20:10:33 [ 4922] [WBXML] [BENUTZER] WBXML-IN : AwFqAEVcT0sDe2MwOWI0OWZkLTYwMTQtNDc2NS1iMDAyLWZkODgzNTYzZTIyYX0xODgAAVIDaS9mNWFiYWVkYgABXgMwAAFTAzAAAVUDNTEyAAFXWAMwAAFiAzIAAWMDOAABABFFRgM0AAFIAzEAAQEBAABWSU0DNDc5AAEBAQEBAQ==
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined->Logoff()
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->close_connection(): IMAP said: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->close_connection(): IMAP said: [CANNOT] Invalid mailbox name: Name is empty (0.000 + 0.000 secs).
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->close_connection(): disconnected from IMAP server
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->SetState() written 833 bytes on file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-bs-1563743265'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendCalDAV->Logoff(): disconnected from CALDAV server
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] BackendCardDAV->Logoff(): disconnected from CARDDAV server
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] Combined->Logoff() success
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] LoopDetection->ProcessLoopDetectionTerminate()
31/07/2019 20:10:33 [ 4922] [ INFO] [BENUTZER] cmd='Sync' memory='2.12 MiB/2.00 MiB' time='0.52s' devType='WindowsOutlook' devId='385887be32ed4f32adb177b4005e1fc4' getUser='BENUTZER' from='192.168.1.42' idle='0s' version='2.5.0+0-0' method='POST' httpcode='200'
31/07/2019 20:10:33 [ 4922] [DEBUG] [BENUTZER] -------- End

Realshadow

@fbartels one more thing. I also just went in and just deleted an email. That was the action that failed in my comment above. When I did that the trash was found. see here:

31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->GetState() read '984' bytes from file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-c09b49fd-6014-4765-b002-fd883563e22a-fd'
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] SyncParameters->UseCPO('DEFAULT')
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->GetState() read '954' bytes from file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-5688b7b3-0b24-4eea-911f-12ddcc695e2a-fd'
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] SyncParameters->UseCPO('DEFAULT')
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->SetMoveStates()
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->SetMoveStates() success
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->ConfigContentParameters()
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->ConfigContentParameters() success
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] DeviceManager->GetBackendIdForFolderId(): no backend-folderid available for 'i/70a7306b', returning as is.
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] ImportChangesCombined->ImportMessageMove('479', 'i/70a7306b')
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->MoveMessage('f5abaedb','479','70a7306b')
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] FileStateMachine->GetState() read '833' bytes from file: '/var/lib/z-push/4/c/385887be32ed4f32adb177b4005e1fc4-bs-1563743265'
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->getImapIdFromFolderId('f5abaedb') = INBOX
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->getImapIdFromFolderId('70a7306b') = Trash
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->imap_inside_cutoffdate(): Checking if the messages is withing the cutoffdate 0, 479
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->imap_inside_cutoffdate(): No cutoffdate, all the messages are in range
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] BackendIMAP->MoveMessage('f5abaedb','479','70a7306b'): result s-move: 'true' s-expunge: 'true' unset-Flags: 'true' set-Flags: 'true'
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O    <Move:Status>
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O    3
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O    </Move:Status>
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O    <Move:DstMsgId>
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O    444
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O    </Move:DstMsgId>
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O   </Move:Response>
31/07/2019 20:26:28 [ 4922] [WBXML] [BENUTZER] O  </Move:Moves>
31/07/2019 20:26:28 [ 4922] [DEBUG] [BENUTZER] WBXMLEncoder->endTag() WBXML output completed

Realshadow

@fbartels OK my last post for tonight. But I wanted to share my analysis. When moving an email (first post) obviously the backend uses a wrong “ID” (actually it is not the ID but the name) for the TRASH folder. that is why that does not work. If instead of the FolderId the function would search for the name of the folder it would probably work but I cannot analyze the code. Therefore I have too little information about the architecture and the structure of which file contains which functions. Goes a little beyond me.

Anyway I really hope you can help me fix that.

Thanks in advance for that.

realshadow

Realshadow

@fbartels and everybody else: any idea how to fix my issue?

Manfred

Hi Realshadow,

it looks like a bug in the imap backend. It doesn’t honour DeletesAsMoves value and tries to move the item to trash folder instead of deleting it. Moving to trash fails because the backend isn’t able to determine the trash folder.

You probably may workaround this issue by commenting out lines 1560-1563 in [z-push-folder]/backend/imap/imap.php:

        $folderImapid = $this->getImapIdFromFolderId($folderid);
/*
        if (strcasecmp($folderImapid, $this->create_name_folder(IMAP_FOLDER_TRASH)) != 0) {
            ZLog::Write(LOGLEVEL_DEBUG, sprintf("BackendIMAP->DeleteMessage('%s','%s') move message to trash folder", $folderid, $id));
            return $this->MoveMessage($folderid, $id, $this->create_name_folder(IMAP_FOLDER_TRASH), $contentparameters);
        }
*/
        $this->imap_reopen_folder($folderImapid);

but someone should fix it properly.

Manfred

practikal

@Realshadow
Hello Realshadow
I’m interesting in instructions how to deploy z-push on NextCloud?
It Is maybe not a “classic” approach/idea but I would like to use/testing the last Raspberry Pi (hardware) like as a cloud server, etc, etc.
Here my e-mail box: practikal@bluewin.ch
Many thanks & regards
Practikal

Realshadow

@practikal I will get back to you shortly. RPI works fine. I used the 3 as my test system before moving the whole setup to a Debian box. The rpi works like a charm for a small setup like 5 to 10 users. Wouldn’t do it for more but usually for a small setup like that it is totally fine. I will send you my doc once cleaned and passwords removed 😁

Realshadow

@Manfred Man you are freaking awesome. That works. Thank you so much. I can now recreate my rules in Outlook and just have them move the emails to my archives. I am really excited. Thank you again.