Open dandinu opened 5 years ago
I faced similar issues.. did you check the grabbit bundle active and running on source and destination servers? check by hitting http://server:port/grabbit/job/all on both servers. if both are running then to get the real error message go to configMgr and enable debug logging for grabbitrecevice and aem error.log. those logs will help you in identifying the root cause of the failure.
Thanks for pointing out the DEBUG
selection in configMgr
@sivaprasad504. I went in and I checked the /grabbit/job/all
on boths systems:
The server displays this (which is normal, since there are were never jobs running on it):
[]
the client displays this (which is fine, since all the jobs are supposed to run on this client, but the FAILED
status still exists):
[{
"transactionID": 1245169299603729269,
"jobExecutionId": 6281385809563395306,
"jcrNodesWritten": -1,
"exitStatus": {
"exitDescription": "",
"exitCode": "FAILED",
"running": false
},
"endTime": "2019-04-17T16:58:29+0000",
"timeTaken": 60161,
"path": "/etc/designs/test-server/clienlibs/test",
"startTime": "2019-04-17T16:57:29+0000"
}, {
"transactionID": 3497236261045048571,
"jobExecutionId": 1421731600700547502,
"jcrNodesWritten": -1,
"exitStatus": {
"exitDescription": "",
"exitCode": "FAILED",
"running": false
},
"endTime": "2019-04-17T16:25:00+0000",
"timeTaken": 60167,
"path": "/etc/designs/test-server/clienlibs/test",
"startTime": "2019-04-17T16:24:00+0000"
}, {
"transactionID": 9051892489963492825,
"jobExecutionId": 6799961264675336536,
"jcrNodesWritten": -1,
"exitStatus": {
"exitDescription": "",
"exitCode": "FAILED",
"running": false
},
"endTime": "2019-04-17T16:12:30+0000",
"timeTaken": 60170,
"path": "/etc/designs/test-server/clienlibs/test",
"startTime": "2019-04-17T16:11:30+0000"
}, {
"transactionID": 6876129364447537021,
"jobExecutionId": 6569392098779498180,
"jcrNodesWritten": -1,
"exitStatus": {
"exitDescription": "",
"exitCode": "FAILED",
"running": false
},
"endTime": "2019-04-17T16:01:42+0000",
"timeTaken": 60112,
"path": "/etc/designs/test-server/clienlibs/test",
"startTime": "2019-04-17T16:00:42+0000"
}, {
"transactionID": 4251115638747771147,
"jobExecutionId": 6678845723766088911,
"jcrNodesWritten": -1,
"exitStatus": {
"exitDescription": "",
"exitCode": "FAILED",
"running": false
},
"endTime": "2019-04-17T15:55:08+0000",
"timeTaken": 60164,
"path": "/etc/designs/test-server/clienlibs/test",
"startTime": "2019-04-17T15:54:08+0000"
}, {
"transactionID": 5772235878355819451,
"jobExecutionId": 8298874135472688390,
"jcrNodesWritten": -1,
"exitStatus": {
"exitDescription": "",
"exitCode": "FAILED",
"running": false
},
"endTime": "2019-04-17T15:51:50+0000",
"timeTaken": 60167,
"path": "/etc/designs/test-server/clienlibs/test",
"startTime": "2019-04-17T15:50:50+0000"
}, {
"transactionID": 4753331250317332505,
"jobExecutionId": 4460668948926338844,
"jcrNodesWritten": -1,
"exitStatus": {
"exitDescription": "",
"exitCode": "FAILED",
"running": false
}
...
TRIMMED FOR BREVITY
After activating the DEBUG
mode in condigMgr
it seems to spit out a bit more info, however still along the same line. Here is what I mean:
24.04.2019 08:28:15.811 *DEBUG* [18.144.0.58 [1556108895809] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.client.servlets.GrabbitJobServlet Input: {
"serverUsername" : "admin",
"serverPassword" : "admin",
"serverHost" : "test-server",
"serverScheme" : "https",
"serverPort" : "443",
"batchSize" : 150,
"deltaContent" : false,
"pathConfigurations" : [
{
"path" : "/etc/designs/test-server/clienlibs/test",
"batchSize" : 50
}
]
}
24.04.2019 08:28:15.863 *DEBUG* [18.144.0.58 [1556108895809] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.client.batch.ClientBatchJob Current Job Params : timestamp=1556108895863,path=/etc/designs/test-server/clienlibs/test,scheme=https,host=test-server,port=443,clientUsername=admin,serverUsername=admin,serverPassword=admin,transactionID=8465422468680473942,excludePaths=,workflowConfigIds=,deleteBeforeWrite=false,pathDeltaContent=false,batchSize=50
24.04.2019 08:28:15.881 *INFO* [18.144.0.58 [1556108895809] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.client.batch.ClientBatchJob Kicked off job with ID : 7642905644041483526
24.04.2019 08:28:15.881 *INFO* [18.144.0.58 [1556108895809] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.client.servlets.GrabbitJobServlet Jobs started : [7642905644041483526]
24.04.2019 08:28:15.881 *INFO* [18.144.0.58 [1556108895809] PUT /grabbit/job HTTP/1.1] com.twcable.grabbit.client.servlets.GrabbitJobServlet Transaction started 8465422468680473942
24.04.2019 08:28:15.886 *DEBUG* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.ClientBatchJobExecutionListener SlingRepository : com.adobe.granite.repository.impl.SlingRepositoryImpl@13fb8ca0
24.04.2019 08:28:15.891 *INFO* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.ClientBatchJobExecutionListener Starting job : JobExecution: id=7642905644041483526, version=1, startTime=Wed Apr 24 08:28:15 EDT 2019, endTime=null, lastUpdated=Wed Apr 24 08:28:15 EDT 2019, status=STARTED, exitStatus=exitCode=UNKNOWN;exitDescription=, job=[JobInstance: id=16, version=0, Job=[clientJob]], jobParameters=[{serverPassword=admin, deleteBeforeWrite=false, scheme=https, port=443, transactionID=8465422468680473942, clientUsername=admin, excludePaths=, workflowConfigIds=, batchSize=50, timestamp=1556108895863, serverUsername=admin, host=test-server, pathDeltaContent=false, path=/etc/designs/test-server/clienlibs/test}]
24.04.2019 08:28:15.891 *DEBUG* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.steps.validation.ValidJobDecider com.twcable.grabbit.client.batch.steps.validation.ValidJobDecider Job determined to be valid for job path /etc/designs/test-server/clienlibs/test
24.04.2019 08:28:15.918 *INFO* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.steps.workflows.WorkflowOffTasklet WorkflowConfig :
24.04.2019 08:28:15.919 *INFO* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.steps.workflows.WorkflowOffTasklet Nothing to process...
24.04.2019 08:28:15.938 *INFO* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.steps.workspace.DeleteBeforeWriteDecider Will retain nodes under job path for 7642905644041483526...
24.04.2019 08:28:30.578 *DEBUG* [18.144.0.58 [1556108910571] GET /grabbit/job/7642905644041483526.json HTTP/1.1] com.twcable.grabbit.client.servlets.GrabbitJobServlet Current Status : {"transactionID":8465422468680473942,"jobExecutionId":7642905644041483526,"jcrNodesWritten":-1,"exitStatus":{"exitDescription":"","exitCode":"UNKNOWN","running":true},"endTime":null,"timeTaken":-1,"path":"/etc/designs/test-server/clienlibs/test","startTime":"2019-04-24T12:28:15+0000"}
24.04.2019 08:29:13.661 *DEBUG* [18.144.0.58 [1556108953656] GET /grabbit/job/7642905644041483526.json HTTP/1.1] com.twcable.grabbit.client.servlets.GrabbitJobServlet Current Status : {"transactionID":8465422468680473942,"jobExecutionId":7642905644041483526,"jcrNodesWritten":-1,"exitStatus":{"exitDescription":"","exitCode":"UNKNOWN","running":true},"endTime":null,"timeTaken":-1,"path":"/etc/designs/test-server/clienlibs/test","startTime":"2019-04-24T12:28:15+0000"}
24.04.2019 08:29:16.047 *INFO* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.ClientBatchJobExecutionListener Cleanup : JobExecution: id=7642905644041483526, version=1, startTime=Wed Apr 24 08:28:15 EDT 2019, endTime=Wed Apr 24 08:29:16 EDT 2019, lastUpdated=Wed Apr 24 08:28:15 EDT 2019, status=FAILED, exitStatus=exitCode=FAILED;exitDescription=, job=[JobInstance: id=16, version=0, Job=[clientJob]], jobParameters=[{serverPassword=admin, deleteBeforeWrite=false, scheme=https, port=443, transactionID=8465422468680473942, clientUsername=admin, excludePaths=, workflowConfigIds=, batchSize=50, timestamp=1556108895863, serverUsername=admin, host=test-server, pathDeltaContent=false, path=/etc/designs/test-server/clienlibs/test}] . Job Complete. Releasing session, and input stream
24.04.2019 08:29:16.051 *INFO* [clientJobLauncherTaskExecutor-6] com.twcable.grabbit.client.batch.ClientBatchJobExecutionListener Grab from test-server for Current Path /etc/designs/test-server/clienlibs/test took : 60166 milliseconds
24.04.2019 08:29:21.977 *DEBUG* [18.144.0.58 [1556108961972] GET /grabbit/job/7642905644041483526.json HTTP/1.1] com.twcable.grabbit.client.servlets.GrabbitJobServlet Current Status : {"transactionID":8465422468680473942,"jobExecutionId":7642905644041483526,"jcrNodesWritten":-1,"exitStatus":{"exitDescription":"","exitCode":"FAILED","running":false},"endTime":"2019-04-24T12:29:16+0000","timeTaken":60166,"path":"/etc/designs/test-server/clienlibs/test","startTime":"2019-04-24T12:28:15+0000"}
24.04.2019 08:39:22.059 *WARN* [18.144.0.58 [1556109562058] GET /grabbit/job/.json HTTP/1.1] com.twcable.grabbit.client.servlets.GrabbitJobServlet Bad request to receive job status for : /grabbit/job/.json. A job ID was not provided in the request.
I'm starting to believe this is some sort of silent timeout error, or something that I do not fully know how to track down. Do you guys know if that might be the case?
Exactly I have faced all these and were able to fix.. it's a default timeout issue. Update timeout setting on both source and destination servers by going to configmgr and search for something with http jetty and update from default 60000 ms which is one hr to 10hrs by adding a zero to it. You will be all set to happy grabbing from then š
Exactly I have faced all these and were able to fix.. it's a default timeout issue. Update timeout setting on both source and destination servers by going to configmgr and search for something with http jetty and update from default 60000 ms which is one hr to 10hrs by adding a zero to it. You will be all set to happy grabbing from then š
Alright, one of the main reasons why the job was always taking around 60 sec, was because of the timeout issue. @sivaprasad504 you had a great suggestion to check that out, because I saw my test-server firewall was blocking the test-client from connecting back.
The funny thing is, now the job fails instantly (156 miliseconds). I would say this is progress, but I am still in the dark about the exact reason:
{
"endTime": "2019-04-25T16:10:16+0000",
"exitStatus": {
"exitCode": "FAILED",
"exitDescription": "",
"running": false
},
"jcrNodesWritten": -1,
"jobExecutionId": 1006534669009632152,
"path": "/etc/designs/test-server/clienlibs/test",
"startTime": "2019-04-25T16:10:16+0000",
"timeTaken": 156,
"transactionID": 3508568264429985364
}
Is there any other more comprehensive log that I can monitor to see why this job fails? Even on DEBUG
the Grabbit logs behave like everything is ok.
I am starting to think that this log message tries to tell me something is wrong, but I cannot figure out what it means:
26.04.2019 08:04:19.347 *DEBUG* [clientJobLauncherTaskExecutor-10] com.twcable.grabbit.client.batch.steps.validation.ValidJobDecider com.twcable.grabbit.client.batch.steps.validation.ValidJobDecider Job determined to be valid for job path /etc/designs/test-server/clienlibs/test
26.04.2019 08:04:19.374 *INFO* [clientJobLauncherTaskExecutor-10] com.twcable.grabbit.client.batch.steps.workflows.WorkflowOffTasklet WorkflowConfig :
26.04.2019 08:04:19.374 *INFO* [clientJobLauncherTaskExecutor-10] com.twcable.grabbit.client.batch.steps.workflows.WorkflowOffTasklet Nothing to process...
26.04.2019 08:04:19.392 *INFO* [clientJobLauncherTaskExecutor-10] com.twcable.grabbit.client.batch.steps.workspace.DeleteBeforeWriteDecider Will retain nodes under job path for 1781941111019933516...
AEM error logshould give you more details on the error, which I'm guessing would be on the timeout of jetty http request. go to configMgr and increase that to few hours and try again.
Note: this needs to be done on both source and destination servers.
Hi @dandinu Can you share following packages if possible i have been trying to get but the links were outdated.
Thanks, Krishna
Hi guys,
I've been trying to sync two AEM systems using Grabbit and everything seems to be installed properly and active in the bundles on both systems. I can succesfully trigger a job, but after I check /CRX/DE, the content is not synced. Here is my info and what I am trying to do.
What version of AEM are you running? AEM 6.4.1 with Grabbit 7.1.5
How do you produce the issue? I installed Grabbit 7.1.5 on both machines and I configured the following
config.json
on the server:I run the following command on the same server where the
config.json
is, and I succesfully trigger a job:curl -v -X PUT --header 'Content-Type: text/plain' --data-binary @/mnt/crx/author/grabbit/config.json -u admin:admin http://test-client:4502/grabbit/job
This is what the
test-client
reports after receiving theconfig.json
:The job is reported as
FAILED
and I do not know why.Does the issue occur consistently? Yes, I am not able to sync the folder at all. here is what it looks like in
./grabbit.sh
:Job when running:
Job when
FAILED
:Help pointing in the right direction Do you guys have any idea what I should be looking at? I have been poking at this for about two days and I can't figure out what's wrong. I'm really hoping someone can point me in the right direction.