StatusException: ExportChangesICS->InitializeExporter(): Error, mapi_exportchanges_config() failed: 0x8004010F - code: 12
-
Hi,
Since yesterday I am getting these kinds of errors:
24/10/2019 23:12:28 [29462] [WARN] [user] StatusException: ExportChangesICS->InitializeExporter(): Error, mapi_exportchanges_config() failed: 0x8004010F - code: 12 - file: /usr/share/z-push/backend/kopano/exporter.php:230
This seems to be the same issue as described in https://forum.kopano.io/topic/1678/statusexception-exportchangesics-initializeexporter-error-mapi_exportchanges_config-failed-0xffffffff8004010f/32 but no solution is provided.
Effectively I cannot sync my phone any more (all tasks are gone from the phone) and I also get millions of:
24/10/2019 23:23:03 [29459] [ INFO] [user] LoopDetection->ProcessLoopDetectionIsHierarchyResyncRequired(): Potential loop detected. Full hierarchysync indicated. 24/10/2019 23:23:03 [29459] [ INFO] [user] cmd='FolderSync' memory='1.79 MiB/2.25 MiB' time='0.59s' devType='iPhone' devId='sf1cn9o2mh19r3g7vr82mnmjfo' getUser='niki' from='216.46.11.210' idle='0s' version='2.5.1+0-0' method='POST' httpcode='200'
which drains my phone battery completely.
I have tried reinstalling z-push completely, deleting entire config/state and removing sync ompletely from phone and setting up again.
Problem persists!I have tried setting “enable_enhanced_ics = no” but doesn’t help either.
I am in huge desperation right now so any help is appreciated!!!
-
Hi @divB,
did that happen out of nowhere? Did you update Z-Push or Kopano or your mobile? Which Kopano version are you using? Are you using Kopano with mySQL or mariadb? Did you restart kopano-server after setting enable_enhanced_ics = no?
Manfred
-
Hi @Manfred,
Somewhere out of nowhere is hard to say: I did not update anything (except once things started to get fishy in hope to remedy things) but I moved the zarafa installation to a different virtual server. So yes, I updated zcp yesterday but all syncs were working initially.
Yes, I restarted server after setting enable_enhanced_ics = no.
Disclaimer: I still use zarafa (zcp) with the Outlook plugin. I know this is not officially supported any more but please don’t make me upgrade ;-) I really do want the Outlook plugin that was dropped. Hence my system also runs on Debian 8 (except the database which runs on Debian 10).
So here are the versions: Debian 8 with zcp-7.2.6.10-debian-8.0-x86_64-supported.tar.gz; mysql Ver 15.1 Distrib 10.3.17-MariaDB; z-push 2.5.1.
So now I have to say my Zarafa database got inconsistent at some point. MAYBE this issue has to do with that and it just never triggered any problems so far. So I would like to ask what is the best way to “repair” the database or make it consistent again?
I used zarafa-admin --clear-cache, --purge-deferred and --force-resync and resynced with Outlook.
In my server.log I see the following entries:
Fri Oct 25 05:38:43 2019: [warning] GetChanges:695 The sync ID 978 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:44 2019: [warning] GetChanges:695 The sync ID 859 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:45 2019: [warning] GetChanges:695 The sync ID 860 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:46 2019: [warning] GetChanges:695 The sync ID 862 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:50 2019: [warning] GetChanges:695 The sync ID 869 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:50 2019: [warning] GetChanges:695 The sync ID 870 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:51 2019: [warning] GetChanges:695 The sync ID 871 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:52 2019: [warning] GetChanges:695 The sync ID 872 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:53 2019: [warning] GetChanges:695 The sync ID 875 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:54 2019: [warning] GetChanges:695 The sync ID 876 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:38:54 2019: [warning] GetChanges:695 The sync ID 877 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:00 2019: [warning] GetChanges:695 The sync ID 886 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:01 2019: [warning] GetChanges:695 The sync ID 888 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:03 2019: [warning] GetChanges:695 The sync ID 890 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:04 2019: [warning] GetChanges:695 The sync ID 891 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:05 2019: [warning] GetChanges:695 The sync ID 892 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:05 2019: [warning] GetChanges:695 The sync ID 893 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:06 2019: [warning] GetChanges:695 The sync ID 895 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:39:07 2019: [info ] No certificate in SSL connection. Fri Oct 25 05:39:31 2019: [crit ] RemoveStaleIndexedProp(): caller wanted to remove the entry, but we cannot since it is in use Fri Oct 25 05:41:07 2019: [crit ] Previous message logged 29 times Fri Oct 25 05:41:07 2019: [warning] GetChanges:695 The sync ID 978 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:41:22 2019: [warning] GetChanges:695 The sync ID 859 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:41:27 2019: [warning] GetChanges:695 The sync ID 860 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:42:13 2019: [warning] GetChanges:695 The sync ID 862 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:43:19 2019: [info ] End of session (timeout) 17944535765187851779 Fri Oct 25 05:43:19 2019: [info ] End of session (timeout) 5926684146701641175 Fri Oct 25 05:43:19 2019: [info ] End of session (timeout) 15833337120442492352 Fri Oct 25 05:43:19 2019: [info ] End of session (timeout) 4995306845455939284 Fri Oct 25 05:48:59 2019: [info ] No certificate in SSL connection. Fri Oct 25 05:49:53 2019: [info ] Previous message logged 64 times Fri Oct 25 05:49:53 2019: [warning] GetChanges:695 The sync ID 869 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:50:03 2019: [warning] GetChanges:695 The sync ID 870 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:50:06 2019: [warning] GetChanges:695 The sync ID 871 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:50:11 2019: [warning] GetChanges:695 The sync ID 872 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:50:31 2019: [info ] No certificate in SSL connection. Fri Oct 25 05:51:34 2019: [info ] Previous message logged 15 times Fri Oct 25 05:51:34 2019: [warning] GetChanges:695 The sync ID 875 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:51:37 2019: [warning] GetChanges:695 The sync ID 876 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:51:39 2019: [warning] GetChanges:695 The sync ID 877 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:51:50 2019: [warning] GetChanges:695 The sync ID 886 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:52:01 2019: [warning] GetChanges:695 The sync ID 888 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:52:41 2019: [warning] GetChanges:695 The sync ID 890 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:52:48 2019: [warning] GetChanges:695 The sync ID 891 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:52:50 2019: [warning] GetChanges:695 The sync ID 892 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:52:52 2019: [warning] GetChanges:695 The sync ID 893 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:52:56 2019: [warning] GetChanges:695 The sync ID 895 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:04 2019: [warning] GetChanges:695 The sync ID 978 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:06 2019: [warning] GetChanges:695 The sync ID 859 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:06 2019: [warning] GetChanges:695 The sync ID 860 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:07 2019: [warning] GetChanges:695 The sync ID 862 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:11 2019: [warning] GetChanges:695 The sync ID 869 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:12 2019: [warning] GetChanges:695 The sync ID 870 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:13 2019: [warning] GetChanges:695 The sync ID 871 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:13 2019: [warning] GetChanges:695 The sync ID 872 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:15 2019: [warning] GetChanges:695 The sync ID 875 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:16 2019: [warning] GetChanges:695 The sync ID 876 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:16 2019: [warning] GetChanges:695 The sync ID 877 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:21 2019: [warning] GetChanges:695 The sync ID 886 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:22 2019: [warning] GetChanges:695 The sync ID 888 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:23 2019: [warning] GetChanges:695 The sync ID 890 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:24 2019: [warning] GetChanges:695 The sync ID 891 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:24 2019: [warning] GetChanges:695 The sync ID 892 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:25 2019: [warning] GetChanges:695 The sync ID 893 does not exist. (unexpected null pointer) session user name: user. Fri Oct 25 05:53:26 2019: [warning] GetChanges:695 The sync ID 895 does not exist. (unexpected null pointer) session user name: user.
Is there a way to get the database consistent first before continuing to debug z-push? (maybe this is related).
At the very least, how can I see which entries the listed “sync IDs” match to and how could I just remove them from the database, in case they are corrupt entries?
UPDATE: This all takes time but it seems that these errors could have been caused by the client cache (rather than the Zarafa database). I followed the instructions from https://webcache.googleusercontent.com/search?q=cache:Yl4eGAcCHKQJ:https://forums.zarafa.com/showthread.php%3F10581-Error-GetChanges+&cd=1&hl=en&ct=clnk&gl=ca and warnings seem to have disappeared.
So I am indeed interested to debug z-push and in particular to understand what the error message means.
-
Hi @divB,
did you connect your mobile again after the following the procedures from the zarafa forum?
The Z-Push errors where caused by PHP-MAPI which is part of the core and were caused by the database errors, so I don’t see a point in debugging Z-Push.
Manfred
-
Hi @Manfred
Ok, thanks!
(Yes, I did delete the profile on the phone and recreated it and also deleted the state at z-push).Ok, then a different question: How can I find out what object belongs to which UUID and how can I delete that object (and all references)? (The database is fairly hard to understand for me and consists of BLOBs)
New messages are as follows (I stripped everything but the relevant lines):
25/10/2019 18:54:09 [11084] [WARN] [user] SyncObject->Check(): Unmet condition in object from type SyncAppointment: parameter 'starttime' is HIGHER than 'endtime'. Check failed! 25/10/2019 18:54:09 [11084] [ERROR] [user] Ignored broken message (SyncAppointment). Reason: '4' Folderid: 'U1b889' message id 'U1b889:0efa6f03327c4d4db2965f7c2f1264c2d802000000000000'
25/10/2019 18:54:29 [11084] [WARN] [user] SyncObject->Check(): Unmet condition in object from type SyncTask: parameter 'startdate' is HIGHER than 'duedate'. Check failed! 25/10/2019 18:54:29 [11084] [ERROR] [user] Ignored broken message (SyncTask). Reason: '4' Folderid: 'U5b6f3' message id 'U5b6f3:0efa6f03327c4d4db2965f7c2f1264c25e2400000000'
25/10/2019 18:54:49 [11084] [ INFO] [user] StateInvalidException: Unexpected synckey value oldcounter: '1' synckey: '{d1408dc5-ef8e-4966-ba03-e3843dff11bc}1' internal key: '{d1408dc5-ef8e-4966-ba03-e3843dff11bc}2' - code: 0 - file: /usr/share/z-push/lib/core/statemanager.php:236 25/10/2019 18:54:49 [11084] [FATAL] [user] WBXML 10K debug data: AwFqAEVcT0sDezg1Y2NlY2IxLTA2ZmUtNGFjMS1hZWQxLTRkOWRlOGM3YzI2NH05AAFSA1U1YjZmMwABAQFVAzIwMAABJgE= 25/10/2019 18:54:49 [11084] [ INFO] [user] User-agent: 'unknown' 25/10/2019 18:54:49 [11084] [FATAL] [user] Exception: (StateInvalidException) - Unexpected synckey value oldcounter: '1' synckey: '{d1408dc5-ef8e-4966-ba03-e3843dff11bc}1' internal key: '{d1408dc5-ef8e-4966-ba03-e3843dff11bc}2'
In particular, which folders are U1b889 and U5b6f3? Which objects are 0efa6f03327c4d4db2965f7c2f1264c2d802000000000000 and 0efa6f03327c4d4db2965f7c2f1264c25e2400000000 and how to delete them?
What is the “synckey” and “internal key” and how do I match them to their UUIDs/objects?
What is WBXML debug data?Thank you!!
PS: Aside, I wonder why I get an error message about a “SyncAppointment” because I have disabled synchronization of appointments. Only syncing tasks right now.
-
Hi @divB,
@divB said in StatusException: ExportChangesICS->InitializeExporter(): Error, mapi_exportchanges_config() failed: 0x8004010F - code: 12:
Hi @Manfred
Ok, thanks!
(Yes, I did delete the profile on the phone and recreated it and also deleted the state at z-push).Ok, then a different question: How can I find out what object belongs to which UUID and how can I delete that object (and all references)? (The database is fairly hard to understand for me and consists of BLOBs)
z-push-admin lists broken messages. Run
z-push-admin -a list -u {username}
. You can then delete those messages in webapp or deskapp.In particular, which folders are U1b889 and U5b6f3? Which objects are 0efa6f03327c4d4db2965f7c2f1264c2d802000000000000 and 0efa6f03327c4d4db2965f7c2f1264c25e2400000000 and how to delete them?
If you have WBXML level log, search for FolderSync command. The short ids for folders are generated there.
In the WBXML level log you can also search for the ids you’ve posted to see which objects they belong to.What is the “synckey” and “internal key” and how do I match them to their UUIDs/objects?
Synckey is an identifier for the synchronisation state of a folder and is actually a UUID with a counter. It’s defined and used by Z-Push, not by Kopano Core.
What is WBXML debug data?
The WBXML data sent by the device.
PS: Aside, I wonder why I get an error message about a “SyncAppointment” because I have disabled synchronization of appointments. Only syncing tasks right now.
You’ll have to check z-push.log if maybe the device still requests calendar sync.
Manfred
-
Hi,
I can confirm, that I am also affected by this “problem”.
The File /var/log/z-push/z-push-error.log is full of messages like these:
27/11/2019 20:27:05 [ 9186] [WARN] [steffi] StatusException: ExportChangesICS->InitializeExporter(): Error, mapi_exportchanges_config() failed: 0xFFFFFFFF8004010F - code: 12 - file: /usr/share/z-push/backend/kopano/exporter.php:230
Software:
- Debian 10 Buster
- Kopano 8.7.85.0.a02e61d66-0+156.1 (from the Kopano download page)
- 2.5.1+0-0 (also from the z-push repo)
(I’m not using the debian packets.)
Does anyone have some tips or hints, how to solve these messages?
Thanks
Robert. -
Hello Forum,
another confirm here.
The Logs are full of this message for several users, but since i couldnt see any resulting issues i decided to just wait.
all users are OK (checked with z-push-admin -a list -u <username>)
most of them are using Outlook 2016 with latest updates and KOEthe code “failed: 0x8004010F - code: 12” should be something like: “object not found”
all versions in my signature
best regards
Coffee_is_life -
There are multiple threads about this topic already with https://forum.kopano.io/topic/1678/statusexception-exportchangesics-initializeexporter-error-mapi_exportchanges_config-failed-0xffffffff8004010f and https://forum.kopano.io/topic/2269/z-push-2-4-5-sync-issue-0xffffffff8004010f (the longer of the two).
What is currently missing is a way to reproduce the error, unless we know how to trigger it, it will be hard to fix.
Closing here.