Protocol message end-group tag did not match expected tag.

[nabello]

Hi my name is Nicola I am an engineer at Infield Design working on OPS tasks involved with AEM. I'm currently trying to setup your Grabbit tool but I've stumbled on an error that I can't seem to resolve. I am trying to sync up content between a dev server and a local instance. Any help would very appreciated. Here is what I get in my error.log when I execute grabbit:

01.05.2015 08:16:31.381 WARN [0:0:0:0:0:0:0:1 [1430493391379] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.resources.GrabbitResourceProvider Unable to find resource for path: /grabbit.
01.05.2015 08:16:31.381 WARN [0:0:0:0:0:0:0:1 [1430493391379] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.GrabbitConfiguration Input doesn't contain deltaContent for a boolean value. Will default to false
01.05.2015 08:16:31.381 INFO [0:0:0:0:0:0:0:1 [1430493391379] PUT /grabbit/job HTTP/1.1] org.springframework.batch.core.launch.support.SimpleJobOperator Checking status of job with name=clientJob
01.05.2015 08:16:31.672 INFO [0:0:0:0:0:0:0:1 [1430493391379] PUT /grabbit/job HTTP/1.1] org.springframework.batch.core.launch.support.SimpleJobOperator Attempting to launch job with name=clientJob and parameters=timestamp=1430493391381,path=/content/someone/en_us,host=IPForServer,port=4502,username=usernameForServer,password=passwordForServer,workflowConfigIds=
01.05.2015 08:16:31.741 INFO [0:0:0:0:0:0:0:1 [1430493391379] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.servlets.GrabbitServlet Jobs started : [7697877024238993081]
01.05.2015 08:16:31.741 INFO [clientJobLauncherTaskExecutor-6] org.springframework.batch.core.launch.support.SimpleJobLauncher Job: [FlowJob: [name=clientJob]] launched with the following parameters: [{workflowConfigIds=, port=4502, password=passwordForServer, host=IPForServer, timestamp=1430493391381, path=/content/someone/en_us, username=usernameForServer}]
01.05.2015 08:16:33.564 INFO [clientJobLauncherTaskExecutor-6] org.springframework.batch.core.job.SimpleStepHandler Executing step: [clientPreprocessor]
01.05.2015 08:16:33.577 ERROR [clientJobLauncherTaskExecutor-6] org.springframework.batch.core.step.AbstractStep Encountered an error executing step clientPreprocessor in job clientJob
com.google.protobuf.InvalidProtocolBufferException: Protocol message end-group tag did not match expected tag.
at com.google.protobuf.InvalidProtocolBufferException.invalidEndTag(InvalidProtocolBufferException.java:73)
at com.google.protobuf.CodedInputStream.checkLastTagWas(CodedInputStream.java:124)
at com.google.protobuf.AbstractMessageLite$Builder.mergeFrom(AbstractMessageLite.java:213)
at com.google.protobuf.AbstractMessage$Builder.mergeFrom(AbstractMessage.java:746)
at com.google.protobuf.AbstractMessage$Builder.mergeFrom(AbstractMessage.java:238)
at com.google.protobuf.AbstractMessageLite$Builder.mergeDelimitedFrom(AbstractMessageLite.java:282)
at com.google.protobuf.AbstractMessage$Builder.mergeDelimitedFrom(AbstractMessage.java:760)
at com.google.protobuf.AbstractMessageLite$Builder.mergeDelimitedFrom(AbstractMessageLite.java:288)
at com.google.protobuf.AbstractMessage$Builder.mergeDelimitedFrom(AbstractMessage.java:752)
at com.twcable.grabbit.proto.PreProcessorProtos$Preprocessors.parseDelimitedFrom(PreProcessorProtos.java:149)
at com.twcable.grabbit.client.batch.steps.preprocessor.PreprocessTasklet.execute(PreprocessTasklet.groovy:53)
at org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:395)
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130)
at org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:267)
at org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:77)
at org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:368)
at org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:215)
at org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:144)
at org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:253)
at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:195)
at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:141)
at org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:64)
at org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:60)
at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:151)
at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:130)
at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:135)
at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:301)
at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:134)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
01.05.2015 08:16:33.617 INFO [clientJobLauncherTaskExecutor-6] org.springframework.batch.core.launch.support.SimpleJobLauncher Job: [FlowJob: [name=clientJob]] completed with the following parameters: [{workflowConfigIds=, port=4502, password=passwordForServer, host=IPForServer, timestamp=1430493391381, path=/content/someone/en_us, username=usernameForServer}] and the following status: [FAILED]

[sagarsane]

Hey Nicola,

Thanks. Have a follow up question, were there any exceptions on the Grabbit Server, and if so, could you provide log information for that too? (what you have here is the Grabbit Client logs) This kind of error happens when there is an exception on the Grabbit Server when marshaling the data using Protocol Buffers.

Also, from the exception on the client, it looks like it failed in the Preprocess step. This step synchronizes the Namespaces between Server and Client.

[nabello]

Hey sagarsane,

Thanks for the help, I went on the server and found this:

04.05.2015 14:16:21.942 INFO [qtp661746363-23743] org.apache.sling.auth.core.impl.SlingAuthenticator getAnonymousResolver: Anonymous access not allowed by configuration - requesting credentials
04.05.2015 14:16:22.020 INFO [IP [1430766982017] GET /grabbit/job HTTP/1.1] org.apache.sling.engine.impl.SlingRequestProcessorImpl service: Resource /grabbit/job not found
04.05.2015 14:16:22.152 WARN [IP [1430766982017] GET /grabbit/job HTTP/1.1] com.day.cq.wcm.msm.impl.LiveRelationshipManagerImpl StarResource given at /content/someone/en_us/errors/500/jcr:content/headerIparsys/: no parent: no LiveCopy
04.05.2015 14:16:22.196 *WARN [IP [1430766982017] GET /grabbit/job HTTP/1.1] com.day.cq.wcm.msm.impl.LiveRelationshipManagerImpl StarResource given at /content/someone/en_us/errors/500/jcr:content/calloutIparsys/: no parent: no LiveCopy
04.05.2015 14:16:22.226 *WARN [IP [1430766982017] GET /grabbit/job HTTP/1.1] com.day.cq.wcm.msm.impl.LiveRelationshipManagerImpl StarResource given at /content/someone/en_us/errors/500/jcr:content/footerIparsys/*: no parent: no LiveCopy

Curiously enough it is not letting me authenticate with AEM even though I have the correct credentials. I just remembered that the git Readme indicates support for AEM 5.6.1 I'm running on AEM 6.0 Service Pack 2. Do you think that is what is blocking me ? Any other thoughts ?

[sagarsane]

Hey @nabello, yes trying to run on AEM 6.0 may be part of the problem.

But just to make sure, can you let me know whether /system/console/bundles on both Grabbit Client and Grabbit Server have all the bundles Active? (Including the Grabbit bundle?)

Also, at least if the Grabbit bundle is not Active, can you let me know what dependencies is it not able to resolve?

[nabello]

Hey @sagarsane, sorry for all the fuss, I just realized that I hadn't installed the bundle on the server. After install works great on AEM 6.0 SP2.

Thanks again for all the help.

Nicola

[jdigger]

Added #30 to make the error message(s) clearer.

[sagarsane]

No problem @nabello glad it worked.