Apache segfaults with z-push 2.3.X



  • Hi all,

    I think I reached the point where I need some help. Since a while I’m running the 2.2. z-push versions to push mails to my personal phone. Since there is a 2.3. available I try to migrate to this version, but to no avail. Somewhere something breaks which leads to segfaults in Apache.

    Tarball, repositories, no difference.

    So I guess it’s time to ask for some help.

    Base system is Ubuntu 14.04.5 LTS
    PHP Version 5.5.9-1ubuntu4.22 (no luck with PHP 7.2.2-1+ubuntu14.04.1+deb.sury.org+1 as well)
    Apache/2.4.7
    z-push 2.3.8
    BackendIMAP

    Basic setup is running, I can access /Microsoft-Server-ActiveSync on my server without any problem, setting up an account on an iphone / ipad also works – but that’s it. Any attempt of z-push to sync anything on the phone throws an apache segfault. Unfortunately, I don’t find anything helpful in the apache logs.

    z-push-error.log

    04/02/2018 21:58:23 [16923] [WARN] [thomas] Unknown:0 Unknown: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN (errflg=1) (8)
    04/02/2018 21:58:29 [16911] [ERROR] [thomas] LoopDetection->ProcessLoopDetectionPreviousConnectionFailed(): Command 'FolderSync' at 04/02/2018 21:52:21 with pid '16873' terminated unexpectedly or is still running.
    04/02/2018 21:58:29 [16911] [ERROR] [thomas] Please check your logs for this PID and errors like PHP-Fatals or Apache segmentation faults and report your results to the Z-Push dev team.
    04/02/2018 21:58:29 [16889] [ERROR] [thomas] LoopDetection->ProcessLoopDetectionPreviousConnectionFailed(): Command 'FolderSync' at 04/02/2018 21:52:27 with pid '16871' terminated unexpectedly or is still running.
    04/02/2018 21:58:29 [16889] [ERROR] [thomas] Please check your logs for this PID and errors like PHP-Fatals or Apache segmentation faults and report your results to the Z-Push dev team.
    

    Maybe this is a hint?

    04/02/2018 22:51:50 [ 2151] [FATAL] [thomas] Fatal error: /usr/share/z-push/backend/imap/imap.php:2344 - Allowed memory size of 134217728 bytes exhausted (tried to allocate 4096 bytes) (1)
    

    These I have in the apache error log as well.

    Memory limit was set to 128M, but 256M or even 512M didn’t help either. Also, no difference between File and SQL StateMachine or deleting the state_dir and starting from scratch.

    I’m somehow out of ideas. Any hint what else I could try? If you need any more info / logs, please let me know.

    Thanks,

    Thomas


  • Kopano

    Hi Thomas,

    how big are your log and state files? Are there any large emails (or emails with large attachments) in your inbox or other folders which would exceed the memory limit?

    Manfred



  • Hi Manfred,

    thanks for your reply!

    I’ve no usable access to the machine right now. I’ll provide you with more infos about the state and log files tonight. For now: Logfiles are rotated regularly and shouldn’t grow to an excessive size, but I’ll check that again and come back later.

    There aren’t mails with an outstanding size, the largest is 30MB. Including this one, there are only 12 mails > 10MB.
    There are 2220 messages and 19 folders (some with subfolders) in the mailbox but if my memory serves me correct, z-push logs something about 22 folders.

    Thomas


  • Kopano

    This doesn’t seem to be a segfault, but an out-of-memory issue. Do you see “segmentation fault” messages in your apache log?
    Just checking: after you changed the memory limit to 512 MB did you restart apache?

    The oom message is weird, because it’s where imap is building the folder path.
    https://stash.z-hub.io/projects/ZP/repos/z-push/browse/src/backend/imap/imap.php?at=refs%2Ftags%2F2.3.8#2344

    Which imap server are you using? Can it be that the folders are being traversed in a loop (e.g. gmail generates a rather particular folder list via imap).

    Could you modify the imap.php backend, adding the following line just before line 2344 (right after the function line)

    ZLog::Write(LOGLEVEL_DEBUG, print_r($fhir, true));
    

    This should print the read list of folders. Perhaps we can see something there.

    Cheers,
    Sebastian



  • Hi Sebastian,

    yes, in the apache logs are segfaults as well (many of these), apache was restarted after configuration change. imap server is dovecot 2.2.9

    [Thu Feb 08 16:40:47.551766 2018] [core:notice] [pid 20152] AH00052: child pid 20202 exit signal Segmentation fault (11)
    

    Manfred,

    Log- and state files looks fine as far as I can say that. Nothing obvious about the size. Just z-push.log is blown up from the debug log.

    z-push.log with modified imap.php (slighty redacted):

    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] -------- Start
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] cmd='FolderSync' devType='iPhone' devId='tvrvv400s97mfbjb2nq2d6jhk4' getUser='thomas' from='1.2.3.4' version='2.3.8+0-0' method='POST'
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] Used timezone 'Europe/Berlin'
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] Request::ProcessHeaders() ASVersion: 14.0
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ZPush::CommandNeedsAuthentication(9): true
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->Logon(): User 'thomas' is authenticated on '{localhost:143/imap/notls/norsh}'
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] FileStateMachine->GetState() read '802' bytes from file: '/var/lib/z-push/4/k/tvrvv400s97mfbjb2nq2d6jhk4-devicedata'
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ASDevice data loaded for user: 'thomas'
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] TopCollector(): Initialized mutexid Resource id #17 and memid Resource id #18.
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] TopCollector initialised with IPC provider 'IpcSharedMemoryProvider' with type '20'
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] LoopDetection(): Initialized mutexid Resource id #21 and memid Resource id #22.
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] LoopDetection initialised with IPC provider 'IpcSharedMemoryProvider' with type '1337'
    08/02/2018 17:40:37 [20202] [ERROR] [thomas] LoopDetection->ProcessLoopDetectionPreviousConnectionFailed(): Command 'FolderSync' at 08/02/2018 17:35:26 with pid '20233' terminated unexpectedly or is still running.
    08/02/2018 17:40:37 [20202] [ERROR] [thomas] Please check your logs for this PID and errors like PHP-Fatals or Apache segmentation faults and report your results to the Z-Push dev team.
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ZPush::HierarchyCommand(9): true
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ZPush::CommandNeedsPlainInput(9): false
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ZPush::GetSupportedProtocolVersions(): 12.0,12.1,14.0
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ZPush::GetSupportedCommands(): Sync,SendMail,SmartForward,SmartReply,GetAttachment,GetHierarchy,CreateCollection,DeleteCollection,MoveCollection,FolderSync,FolderCreate,FolderDelete,FolderUpdate,MoveItems,GetItemEstimate,MeetingResponse,ResolveRecipients,ValidateCert,Provision,Search,Ping,Notify,ItemOperations,Settings
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ASDevice->GetHierarchyCache(): HierarchyCache is up - Cached objects: 0
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] LoopDetection->ProcessLoopDetectionAddStatus: 'hierarchy' with status 1
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] WBXMLEncoder->startWBXML() type: vnd.ms-sync.wbxml
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] ExportChangesDiff->InitializeExporter(): Initializing folder diff engine
    08/02/2018 17:40:37 [20202] [ INFO] [thomas] StateNotFoundException: FileStateMachine->GetState(): Could not locate state '/var/lib/z-push/4/k/tvrvv400s97mfbjb2nq2d6jhk4-bs-1518107970' - code: 0 - file: /usr/share/z-push/lib/default/filestatemachine.php:119
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX') IMAP cache folder not found, creating one
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX') = c43a5c95
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Sent') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Sent') = 17e4489b
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Junk-E-Mail') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Junk-E-Mail') = a7635bf2
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Drafts') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Drafts') = 94cac65f
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Trash') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Trash') = e073edff
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('0.Junk') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('0.Junk') = ab5942ec
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('0.Archive') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('0.Archive') = bfc39f71
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.Unwanted-E-Mail') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.Unwanted-E-Mail') = 49aa4cd1
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.aaaa') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.aaaa') = 24ea3ca4
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.bbbb') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.bbbb') = 35817aef
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.cccc') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.cccc') = cec16908
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.dddd') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.dddd') = ac2c7a1c
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx') = 59b1b96a
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.yyyy.aaaa') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.yyyy.aaaa') = 1f705278
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.yyyy') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.yyyy') = e3c72bd9
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General.aaaa') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General.aaaa') = b227c084
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General.aaaa') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General.aaaa') = 52b3cddd
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General.aaaa') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General.aaaa') = 88a5de7c
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General') = f50fbc6a
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.bbbb.aaaa') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.bbbb.aaaa') = 35ef9e47
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.bbbb.bbbb') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.bbbb.bbbb') = 7762e10f
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.bbbb') = not found
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.bbbb') = 8b632165
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX') = c43a5c95
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX') = c43a5c95
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Sent') = 17e4489b
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Sent') = 17e4489b
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Junk-E-Mail') = a7635bf2
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Junk-E-Mail') = a7635bf2
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Drafts') = 94cac65f
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Drafts') = 94cac65f
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('Trash') = e073edff
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('Trash') = e073edff
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('0.Junk') = ab5942ec
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('0.Junk') = ab5942ec
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('0.Archive') = bfc39f71
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('0.Archive') = bfc39f71
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.Unwanted-E-Mail') = 49aa4cd1
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.Unwanted-E-Mail') = 49aa4cd1
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.aaaa') = 24ea3ca4
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.aaaa') = 24ea3ca4
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.aaaa') = 35817aef
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.bbbb') = 35817aef
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.bbbb') = cec16908
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.bbbb') = cec16908
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx.cccc') = ac2c7a1c
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx.cccc') = ac2c7a1c
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.xxxx') = 59b1b96a
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.xxxx') = 59b1b96a
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.bbbb.aaaa') = 1f705278
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.bbbb.aaaa') = 1f705278
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.bbbb') = e3c72bd9
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.bbbb') = e3c72bd9
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General.aaaa') = b227c084
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General.aaaa') = b227c084
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General.bbbb') = 52b3cddd
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General.bbbb') = 52b3cddd
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General.cccc') = 88a5de7c
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General.cccc') = 88a5de7c
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.General') = f50fbc6a
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.General') = f50fbc6a
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.cccc.aaaa') = 35ef9e47
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.cccc.aaaa') = 35ef9e47
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.cccc.bbbb') = 7762e10f
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.cccc.bbbb') = 7762e10f
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getFolderIdFromImapId('INBOX.cccc') = 8b632165
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->convertImapId('INBOX.cccc') = 8b632165
    08/02/2018 17:40:37 [20202] [ INFO] [thomas] ExportChangesDiff->InitializeExporter(): Found '22' changes for 'hierarchy'
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] BackendIMAP->getImapIdFromFolderId('c43a5c95') = INBOX
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] Array
    (
    )
    
    08/02/2018 17:40:37 [20202] [DEBUG] [thomas] Array
    (
    )
    

    …continues like that

    Thomas


  • Kopano

    Could you upload/post the complete log somewhere? Especially until it runs out of memory.

    Do the PIDs from your apache log match the z-push logs where the request fails?
    Are there other (PHP) scripts running or better: is apache serving other content that could be responsible for the segfaults?



  • Hi Sebastian,

    I’ve send you a link to the log.
    Yes, the PIDs are matching and there is not really much more running in the background, just roundcube as webmailer.

    /e:
    With PHP7.2 I get the followingin apaches error.log

    [Thu Feb 08 21:12:16.247818 2018] [php7:error] [pid 25910] [client 1.2.3.4:56789] PHP Fatal error:  Allowed memory size of 536870912 bytes exhausted (tried to allocate 20480 bytes) in /usr/share/z-push/lib/core/zlog.php on line 216
    


  • Hi,

    short heads up here:

    To exclude an apache issue here, I switched over to lighttpd - with the same problem.
    Next idea was to copy the imap backend from the working 2.2.13 to the new 2.3.9 z-push - and synchronization started to kind of work.
    The subject lines are synched to my mobile device, the body is missing (“This message was not downloaded”)

    The log is full with these entries - kind of obvious as I messed up two complete different backend versions:

    11/02/2018 14:32:39 [ 5151] [ INFO] [thomas] cmd='Sync' memory='2.02 MiB/2.00 MiB' time='0.07s' devType='iPad' devId='c3l4i6rild0q9c1bbl254pejfc' getUser='thomas' from='1.2.3.4' idle='0s' version='2.3.9+0-0' method='POST' httpcode='200'
    11/02/2018 14:32:39 [ 5150] [WARN] [thomas] /usr/share/z-push/include/mimeDecode.php:525 Uninitialized string offset: 0 (8)
    11/02/2018 14:32:39 [ 5150] [WARN] [thomas] /usr/share/z-push/lib/wbxml/wbxmlencoder.php:172 stream_filter_append() expects parameter 1 to be resource, string given (2)
    11/02/2018 14:32:39 [ 5150] [WARN] [thomas] /usr/share/z-push/lib/wbxml/wbxmlencoder.php:295 stream_copy_to_stream() expects parameter 1 to be resource, string given (2)
    11/02/2018 14:32:39 [ 5150] [WARN] [thomas] /usr/share/z-push/lib/wbxml/wbxmlencoder.php:179 stream_filter_remove() expects parameter 1 to be resource, boolean given (2)
    11/02/2018 14:32:39 [ 5150] [WARN] [thomas] /usr/share/z-push/lib/wbxml/wbxmlencoder.php:182 fclose() expects parameter 1 to be resource, string given (2)
    11/02/2018 14:32:39 [ 5150] [ INFO] [thomas] cmd='Sync' memory='2.02 MiB/2.00 MiB' time='0.07s' devType='iPad' devId='c3l4i6rild0q9c1bbl254pejfc' getUser='thomas' from='1.2.3.4' idle='0s' version='2.3.9+0-0' method='POST' httpcode='200'
    11/02/2018 14:32:39 [ 5152] [ INFO] [thomas] ExportChangesDiff->InitializeExporter(): Found '0' changes for '8caf2517'
    11/02/2018 14:32:39 [ 5152] [ INFO] [thomas] cmd='Sync' memory='2.13 MiB/2.00 MiB' time='0.12s' devType='iPad' devId='c3l4i6rild0q9c1bbl254pejfc' getUser='thomas' from='1.2.3.4' idle='0s' version='2.3.9+0-0' method='POST' httpcode='200'
    11/02/2018 14:32:42 [ 5153] [ INFO] [thomas] SyncCollections->CheckForChanges(): Waiting for store changes... (lifetime 600 seconds)
    11/02/2018 14:32:42 [ 5153] [ INFO] [thomas] ExportChangesDiff->InitializeExporter(): Found '3' changes for 'hierarchy'
    

    Inbetween I found out about a dependency with libawl-php - which already was installed but, just to be sure, I installed a new version from https://gitlab.com/davical-project/awl - which didn’t help nontheless.

    Maybe my imap config is botched? I guess the imap backend got a complete overhaul from z-push 2.2. to 2.3.
    Part of the config which I’m using (the only changed part):

    // Since I know you won't configure this, I will raise an error unless you do.
    // When configured set this to true to remove the error
    define('IMAP_FOLDER_CONFIGURED', true);
    
    // Folder prefix is the common part in your names (3, 4)
    define('IMAP_FOLDER_PREFIX', 'INBOX');
    
    // Inbox will have the preffix preppend (3 & 4 to true)
    define('IMAP_FOLDER_PREFIX_IN_INBOX', false);
    
    // Inbox folder name (case doesn't matter) - (empty in 4)
    define('IMAP_FOLDER_INBOX', '');
    
    // Sent folder name (case doesn't matter)
    define('IMAP_FOLDER_SENT', 'SENT');
    
    // Draft folder name (case doesn't matter)
    define('IMAP_FOLDER_DRAFT', 'DRAFTS');
    
    // Trash folder name (case doesn't matter)
    define('IMAP_FOLDER_TRASH', 'TRASH');
    
    // Spam folder name (case doesn't matter). Only showed as special by iOS devices
    define('IMAP_FOLDER_SPAM', 'Junk-E-Mail');
    
    // Archive folder name (case doesn't matter). Only showed as special by iOS devices
    define('IMAP_FOLDER_ARCHIVE', 'ARCHIVE');
    

    Folder structure:

    drwx------ 26 thomas thomas    4096 Feb 11 13:52 ./
    drwxr-xr-x 20 thomas thomas    4096 Jan 30 20:39 ../
    drwx------  5 thomas thomas    4096 Feb  9 20:52 .0.Archive/
    drwx------  5 thomas thomas    4096 Feb  9 20:52 .0.Junk/
    drwx------  2 thomas thomas  159744 Feb 11 11:41 cur/
    -rw-------  1 thomas thomas   53656 Feb 10 19:27 dovecot.index
    -rw-------  1 thomas thomas 2242640 Feb 11 11:41 dovecot.index.cache
    -rw-------  1 thomas thomas   11252 Feb 11 13:27 dovecot.index.log
    -rw-------  1 thomas thomas   32856 Feb 10 19:27 dovecot.index.log.2
    -rw-------  1 thomas thomas      24 Jun 19  2015 dovecot-keywords
    -rw-------  1 thomas thomas    1968 Jun  7  2017 dovecot.mailbox.log
    -rw-------  1 thomas thomas  124283 Feb 11 11:41 dovecot-uidlist
    -rw-------  1 thomas thomas       8 Feb  9 20:52 dovecot-uidvalidity
    -r--r--r--  1 thomas thomas       0 Jun 19  2015 dovecot-uidvalidity.55847a4a
    drwx------  5 thomas thomas    4096 Feb  7 10:01 .Drafts/
    drwx------  5 thomas thomas    4096 Feb  3 16:10 .INBOX.Arbeit/
    drwx------  5 thomas thomas    4096 Feb  3 16:10 .INBOX.Arbeit.ABC/
    drwx------  5 thomas thomas    4096 Jun 19  2015 .INBOX.Familie/
    drwx------  5 thomas thomas    4096 Feb  3 16:10 .INBOX.Familie.AAA/
    drwx------  5 thomas thomas    4096 Feb  3 16:10 .INBOX.Familie.BBB/
    drwx------  5 thomas thomas    4096 Feb  3 16:10 .INBOX.Familie.CCC/
    drwx------  5 thomas thomas    4096 Feb  3 16:10 .INBOX.Familie.DDD/
    drwx------  5 thomas thomas    4096 Jun 19  2015 .INBOX.Freunde/
    drwx------  5 thomas thomas    4096 Feb  3 16:11 .INBOX.Freunde.AAA/
    drwx------  5 thomas thomas    4096 Feb  3 16:10 .INBOX.Freunde.BBB/
    drwx------  5 thomas thomas    4096 Jun 19  2015 .INBOX.General/
    drwx------  5 thomas thomas    4096 Feb  3 16:11 .INBOX.General.AAA/
    drwx------  5 thomas thomas    4096 Feb  3 16:11 .INBOX.General.BBB/
    drwx------  5 thomas thomas    4096 Feb  3 16:11 .INBOX.General.CCC/
    drwx------  5 thomas thomas    4096 Feb  2 21:46 .INBOX.Unwanted-E-Mail/
    drwx------  5 thomas thomas    4096 Feb 11 09:39 .Junk-E-Mail/
    -rw-------  1 thomas thomas       0 Jun 19  2015 maildirfolder
    drwx------  2 thomas thomas    4096 Feb 11 11:41 new/
    drwx------  5 thomas thomas    4096 Feb 11 13:52 .Sent/
    -rw-------  1 thomas thomas     338 Jun  7  2017 subscriptions
    drwx------  2 thomas thomas    4096 Feb 11 11:37 tmp/
    drwx------  5 thomas thomas    4096 Feb 11 11:41 .Trash/
    

    New mail goes to cur - which has no prefix. I tried that in the config above as well - without luck

    Honestly, I have no clue what to try anymore. Any help is greatly appreciated, as I don’t want to be stuck with z-push 2.2.13 until doomsday.

    Thomas


  • Kopano

    Hi Thomas,

    simply copying imap.php from Z-Push 2.2 into Z-Push 2.3 won’t work as there were too many changes.

    On my test dovecot server the only change I make in config.php of IMAP backend is setting IMAP_FOLDER_CONFIGURED to true and leaving everything else as is.

    Manfred



  • Hi Manfred,

    I just gave it one more try (with the tarball this time) and, holy mackerel, it just WORKS!

    Thanks for the tip with the IMAP config! I guess that was the culprit.

    Thomas


Log in to reply