wttech / CQ-Unix-Toolkit

CQ Unix Toolkit
46 stars 23 forks source link

cqsnp creates a zip file despite 404 from CQ #35

Closed jwadolowski closed 9 years ago

jwadolowski commented 9 years ago

Hey,

my test environment was like this:

Name Group Version
cq-package com.example.cq 0.4.0
cq-package com.example.cq 0.4.2
cq-package com.example.cq 0.5.0
cq-package com.example.cq 0.5.5

I've executed ~/projects/CQ-Unix-Toolkit/cqsnp -i http://localhost:4502 -u admin -p admin cq-package and it returned the following output:

HTTP RESPONSE 404: Not found or forbidden: please check permissions
Cannot find snapshot for: [G=:N=cq-package:V=1.0]

Surprisingly a zip file was created on my file system: cq-package-1.0-undo.zip. I've tried to extract its contents, but both unzip and jar failed.

 End-of-central-directory signature not found.  Either this file is not
  a zipfile, or it constitutes one disk of a multi-part archive.  In the
  latter case the central directory and zipfile comment will be found on
  the last disk(s) of this archive.

Cheers, Kuba

jwadolowski commented 9 years ago

It seems to be even worse - zip file was created when:

$ ~/projects/CQ-Unix-Toolkit/cqsnp -i http://192.168.123.100:4502 -u admin -p admin -v 0.2.9 cq-package
HTTP RESPONSE 404: Not found or forbidden: please check permissions
Cannot find snapshot for: [G=:N=cq-package:V=0.2.9]
$ ~/projects/CQ-Unix-Toolkit/cqsnp -i http://192.168.123.100:4502 -u admin -p admin -g com.fake.group cq-package
HTTP RESPONSE 404: Not found or forbidden: please check permissions
Cannot find snapshot for: [G=com.fake.group:N=cq-package:V=1.0]
$ ~/projects/CQ-Unix-Toolkit/cqsnp -i http://192.168.123.100:4502 -u admin -p admin -v 0.2.9 -g com.fake.group cq-package
HTTP RESPONSE 404: Not found or forbidden: please check permissions
Cannot find snapshot for: [G=com.fake.group:N=cq-package:V=0.2.9]
$ ~/projects/CQ-Unix-Toolkit/cqsnp -i http://192.168.123.100:4502 -u admin -p admin not-existing-package
HTTP RESPONSE 404: Not found or forbidden: please check permissions
Cannot find snapshot for: [G=:N=not-existing-package:V=1.0]
jwadolowski commented 9 years ago

It turned out the reason why I wasn't able to extract such zip files was quite obvious - instead of a ZIP file an HTML error page was saved. Here's an example:

<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html>
    <head><title>404 Not Found</title></head>
    <body>
        <h1>Not Found</h1>
        <p>Cannot serve request to /etc/packages/.snapshot/not-existing-package-1.0.zip in org.apache.sling.servlets.get.DefaultGetServlet</p>

        <h3>Request Progress:</h3>
<pre>
      0 (2015-05-06 13:18:43) TIMER_START{Request Processing}
      0 (2015-05-06 13:18:43) COMMENT timer_end format is {&lt;elapsed msec&gt;,&lt;timer name&gt;} &lt;optional message&gt;
      0 (2015-05-06 13:18:43) LOG Method=GET, PathInfo=/etc/packages/.snapshot/not-existing-package-1.0.zip
      0 (2015-05-06 13:18:43) TIMER_START{ResourceResolution}
      1 (2015-05-06 13:18:43) TIMER_END{1,ResourceResolution} URI=/etc/packages/.snapshot/not-existing-package-1.0.zip resolves to Resource=JcrNodeResource, type=cq/packaging/components/manager, superType=null, path=/etc/packages
      1 (2015-05-06 13:18:43) LOG Resource Path Info: SlingRequestPathInfo: path='/etc/packages/', selectorString='null', extension='snapshot', suffix='/not-existing-package-1.0.zip'
      1 (2015-05-06 13:18:43) TIMER_START{ServletResolution}
      1 (2015-05-06 13:18:43) TIMER_START{resolveServlet(JcrNodeResource, type=cq/packaging/components/manager, superType=null, path=/etc/packages)}
      1 (2015-05-06 13:18:43) TIMER_END{0,resolveServlet(JcrNodeResource, type=cq/packaging/components/manager, superType=null, path=/etc/packages)} Using servlet org.apache.sling.servlets.get.DefaultGetServlet
      1 (2015-05-06 13:18:43) TIMER_END{0,ServletResolution} URI=/etc/packages/.snapshot/not-existing-package-1.0.zip handled by Servlet=org.apache.sling.servlets.get.DefaultGetServlet
      1 (2015-05-06 13:18:43) LOG Applying Requestfilters
      1 (2015-05-06 13:18:43) LOG Calling filter: org.apache.sling.bgservlets.impl.BackgroundServletStarterFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: org.apache.sling.i18n.impl.I18NFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: org.apache.sling.rewriter.impl.RewriterFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.designimporter.CanvasPageDeleteRequestFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.adobe.cq.history.impl.HistoryRequestFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.core.impl.WCMRequestFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.adobe.granite.optout.impl.OptOutFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.theme.impl.ThemeResolverFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.foundation.forms.impl.FormsHandlingServlet
      1 (2015-05-06 13:18:43) LOG Calling filter: org.apache.sling.engine.impl.debug.RequestProgressTrackerLogFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.mobile.core.impl.redirect.RedirectFilter
      1 (2015-05-06 13:18:43) LOG RedirectFilter did not redirect (request extension does not match)
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.core.impl.warp.TimeWarpFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.core.impl.AuthoringUIModeServiceImpl
      1 (2015-05-06 13:18:43) LOG Applying Componentfilters
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.personalization.impl.TargetComponentFilter
      1 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.core.impl.WCMComponentFilter
      2 (2015-05-06 13:18:43) LOG Calling filter: com.day.cq.wcm.core.impl.WCMDebugFilter
      2 (2015-05-06 13:18:43) TIMER_START{org.apache.sling.servlets.get.DefaultGetServlet#0}
      2 (2015-05-06 13:18:43) LOG No renderer for extension snapshot
      2 (2015-05-06 13:18:43) LOG Applying Error filters
      2 (2015-05-06 13:18:43) LOG Calling filter: org.apache.sling.rewriter.impl.RewriterFilter
      2 (2015-05-06 13:18:43) TIMER_START{handleError:status=404}
      2 (2015-05-06 13:18:43) TIMER_END{0,handleError:status=404} Using handler /libs/sling/servlet/errorhandler/404.jsp
      2 (2015-05-06 13:18:43) LOG Found processor for post processing ProcessorConfiguration: {contentTypes=[text/html],order=-1, active=true, valid=true, processErrorResponse=true, pipeline=(generator=Config(type=htmlparser, config={}), transformers=(Config(type=linkchecker, config={}), Config(type=mobile, config=JcrPropertyMap [node=node /libs/cq/config/rewriter/default/transformer-mobile, values={jcr:primaryType=nt:unstructured, component-optional=true}]), Config(type=mobiledebug, config=JcrPropertyMap [node=node /libs/cq/config/rewriter/default/transformer-mobiledebug, values={jcr:primaryType=nt:unstructured, component-optional=true}]), Config(type=contentsync, config=JcrPropertyMap [node=node /libs/cq/config/rewriter/default/transformer-contentsync, values={jcr:primaryType=nt:unstructured, component-optional=true}]), serializer=Config(type=htmlwriter, config={}))}
      3 (2015-05-06 13:18:43) TIMER_END{3,Request Processing} Dumping SlingRequestProgressTracker Entries
</pre>

        <hr>
        <address>ApacheSling/2.2 (Day-Servlet-Engine/4.1.52, Java HotSpot(TM) 64-Bit Server VM 1.7.0_72, Linux 2.6.32-504.el6.x86_64 amd64)</address>
    </body>
</html>
jwadolowski commented 9 years ago

One last thing - when I tried to use -d flag with invalid params the fake zip file was still created. Same scenario (fake data) with -d -0 didn't create a file, but I can see the following request in CQ access.log:

192.168.123.1 - admin 06/May/2015:13:41:43 +0000 "GET /etc/packages/a.b.c.d/.snapshot/test123-0.5.11.zip HTTP/1.1" 404 5288 "http://192.168.123.100:4502/etc/packages" "curl/7.35.0"

It looks rather odd to me, as I expected just a DELETE request, not a GET one (my intention was to delete a snapshot, not to download it).

kitarek commented 9 years ago

Hi,

this issue has been fixed in CQM-119 branch. However please note that there is an extra HEAD request to check snapshot status.

The same is for -d -0 - still HEAD and GET requests are issued before DELETE because the destination download file is just /dev/null. Let me know if you think this needs to be absolutely changed.

Thanks, Arek

kitarek commented 9 years ago

Please reopen if if there is a still the same or related problem. Thanks Jakub!

jwadolowski commented 9 years ago

Hey,

I've just successfully retested your recent changes on CQ5.6.1 and AEM6. All reported issues are gone.

Thanks!