From oak-dev-return-3224-apmail-jackrabbit-oak-dev-archive=jackrabbit.apache.org@jackrabbit.apache.org Mon Jan 14 13:50:47 2013 Return-Path: X-Original-To: apmail-jackrabbit-oak-dev-archive@minotaur.apache.org Delivered-To: apmail-jackrabbit-oak-dev-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 8950FEF02 for ; Mon, 14 Jan 2013 13:50:47 +0000 (UTC) Received: (qmail 94735 invoked by uid 500); 14 Jan 2013 13:50:47 -0000 Delivered-To: apmail-jackrabbit-oak-dev-archive@jackrabbit.apache.org Received: (qmail 94598 invoked by uid 500); 14 Jan 2013 13:50:45 -0000 Mailing-List: contact oak-dev-help@jackrabbit.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: oak-dev@jackrabbit.apache.org Delivered-To: mailing list oak-dev@jackrabbit.apache.org Received: (qmail 94576 invoked by uid 99); 14 Jan 2013 13:50:44 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 14 Jan 2013 13:50:44 +0000 X-ASF-Spam-Status: No, hits=0.5 required=5.0 tests=HTML_IMAGE_RATIO_04,HTML_MESSAGE,RCVD_IN_DNSWL_MED,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of gbuchana@adobe.com designates 64.18.1.31 as permitted sender) Received: from [64.18.1.31] (HELO exprod6og113.obsmtp.com) (64.18.1.31) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 14 Jan 2013 13:50:31 +0000 Received: from outbound-smtp-1.corp.adobe.com ([192.150.11.134]) by exprod6ob113.postini.com ([64.18.5.12]) with SMTP ID DSNKUPQNELvdidxprMOo7n/JoznwLubCa1Qp@postini.com; Mon, 14 Jan 2013 05:50:09 PST Received: from inner-relay-1.corp.adobe.com ([153.32.1.51]) by outbound-smtp-1.corp.adobe.com (8.12.10/8.12.10) with ESMTP id r0EDl71v020050 for ; Mon, 14 Jan 2013 05:47:07 -0800 (PST) Received: from nahub01.corp.adobe.com (nahub01.corp.adobe.com [10.8.189.97]) by inner-relay-1.corp.adobe.com (8.12.10/8.12.10) with ESMTP id r0EDo6AX006533 for ; Mon, 14 Jan 2013 05:50:07 -0800 (PST) Received: from nambx03.corp.adobe.com ([10.8.189.93]) by nahub01.corp.adobe.com ([10.8.189.97]) with mapi; Mon, 14 Jan 2013 05:50:06 -0800 From: Gardner Buchanan To: "oak-dev@jackrabbit.apache.org" Date: Mon, 14 Jan 2013 05:50:05 -0800 Subject: Hung thread in OAK CRX -- maybe a bug to look into Thread-Topic: Hung thread in OAK CRX -- maybe a bug to look into Thread-Index: Ac3wSwOhW32HF35bQjC9qK4BN/G11wCEmpcQ Message-ID: <686848D3189C0845A6E5FA781D6A0FFF373528BDE3@nambx03.corp.adobe.com> Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: yes X-MS-TNEF-Correlator: acceptlanguage: en-US Content-Type: multipart/related; boundary="_005_686848D3189C0845A6E5FA781D6A0FFF373528BDE3nambx03corpad_"; type="multipart/alternative" MIME-Version: 1.0 X-Virus-Checked: Checked by ClamAV on apache.org --_005_686848D3189C0845A6E5FA781D6A0FFF373528BDE3nambx03corpad_ Content-Type: multipart/alternative; boundary="_000_686848D3189C0845A6E5FA781D6A0FFF373528BDE3nambx03corpad_" --_000_686848D3189C0845A6E5FA781D6A0FFF373528BDE3nambx03corpad_ Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable Hi all, I've been experimenting a bit with Oak and ran into something I thought I w= ould share, in case there is a worthwhile bug to investigate. I have com.a= dobe.granite.quickstart-2012.22-SNAPSHOT.jar, which is rather old now, but = looks to be the latest CRX build that hangs together. The test case involv= es a number of concurrent threads, creating different parts of a node hiera= rchy concurrently, via curl POSTs, such as: command=3D/usr/bin/curl -sSo /dev/null -u admin:admin -F jcr:primaryType=3D= nt:folder "http://chartis_a.ottperflab.corp.adobe.com:4502/content/folder/8= 4/32" command=3D/usr/bin/curl -sSo /dev/null -u admin:admin -F jcr:primaryType=3D= nt:folder "http://chartis_a.ottperflab.corp.adobe.com:4502/content/folder/8= 4/32/25" command=3D/usr/bin/curl -sSo /dev/null -u admin:admin -F jcr:primaryType=3D= nt:folder "http://chartis_a.ottperflab.corp.adobe.com:4502/content/folder/8= 4/32/25/72" command=3D/usr/bin/curl -sSo /dev/null -u admin:admin -F jcr:primaryType=3D= nt:folder "http://chartis_a.ottperflab.corp.adobe.com:4502/content/folder/8= 4/32/25/72/6" command=3D/usr/bin/curl -sSo /dev/null -u admin:admin -F jcr:primaryType=3D= nt:folder "http://chartis_a.ottperflab.corp.adobe.com:4502/content/folder/8= 6" command=3D/usr/bin/curl -sSo /dev/null -u admin:admin -F jcr:primaryType=3D= nt:folder "http://chartis_a.ottperflab.corp.adobe.com:4502/content/folder/8= 6/00" What happened in my test case is that one of the threads hung whilst creati= ng /content/folder/86/00. You can see the progress of the various threads = here: [cid:image001.png@01CDF234.26111F90] This thread is not blocked however, but seems to be stuck in a loop, and it= is constantly running doing something. If you care to look, there's a Yourkit profiling snapshot with this stuck t= hread here: \\ottfs01\users_g\gbuchana\MyTransfer\com.adobe.granite.quickstart-2012.22-= SNAPSHOT-2013-01-11(2).snapshot >From the profiler snapshot I captured, it appears to be stuck in: org.apac= he.sling.servlets.post.impl.operations.AbstractCreateOperation.deepGetOrCre= ateNode() Where it is making a whole slew of repeated calls to various things [cid:image002.png@01CDF234.26111F90] Looking at the source code for deepGetOrCreateNode(), it would appear to be= stuck in this loop: 478 Resource startingResource =3D null; 479 while (startingResource =3D=3D null) { 480 if (startingResourcePath.equals("/")) { 481 startingResource =3D resolver.getResource("/"); 482 } else if (resolver.getResource(startingResourcePath) !=3D null) { 483 startingResource =3D resolver.getResource(startingResourcePath); 484 updateNodeType(resolver, startingResourcePath, reqProperties, ch= anges, versioningConfiguration); 485 updateMixins(resolver, startingResourcePath, reqProperties, chan= ges, versioningConfiguration); 486 } else { 487 int pos =3D startingResourcePath.lastIndexOf('/'); 488 if (pos > 0) { 489 startingResourcePath =3D startingResourcePath.substring(0, pos= ); 490 } else { 491 startingResourcePath =3D "/"; 492 } 493 } 494 } Gardner Buchanan Adobe Systems Canada Office: +1 613 940 3842 Mobile: +1 613 884 7940 --_000_686848D3189C0845A6E5FA781D6A0FFF373528BDE3nambx03corpad_ Content-Type: text/html; charset="us-ascii" Content-Transfer-Encoding: quoted-printable

Hi all,

 

I've been experimenting a bit wit= h Oak and ran into something I thought I would share, in case there is a wo= rthwhile bug to investigate.  I have com.adobe.granite.quickstart-2012= .22-SNAPSHOT.jar, which is rather old now, but looks to be the latest CRX b= uild that hangs together.  The test case involves a number of concurre= nt threads, creating different parts of a node hierarchy concurrently, via = curl POSTs, such as:

 

command=3D/usr/bin/curl -sSo /dev/null -u admin= :admin -F jcr:primaryType=3Dnt:folder "http://chartis_a.ottperfl= ab.corp.adobe.com:4502/content/folder/84/32"

=

command=3D/usr/bin/curl -sSo /dev/null = -u admin:admin -F jcr:primaryType=3Dnt:folder "http://chartis= _a.ottperflab.corp.adobe.com:4502/content/folder/84/32/25"

command=3D/usr/bin/curl -= sSo /dev/null -u admin:admin -F jcr:primaryType=3Dnt:folder "http://chartis_a.ottperflab.corp.adobe.com:4502/content/folder/84/32/2= 5/72"

com= mand=3D/usr/bin/curl -sSo /dev/null -u admin:admin -F jcr:primaryType=3Dnt:= folder "http://chartis_a.ottperflab.corp.adobe.com:4502/= content/folder/84/32/25/72/6"

command=3D/usr/bin/curl -sSo /dev/null -u admin:admin = -F jcr:primaryType=3Dnt:folder "http://chartis_a.ottperflab.corp.ad= obe.com:4502/content/folder/86"

command=3D/usr/bin/curl -sSo /dev/null -u admin:admi= n -F jcr:primaryType=3Dnt:folder "http://chartis_a.ottperflab.co= rp.adobe.com:4502/content/folder/86/00"

 = ;

What happened in my test case is that one of the threads hung = whilst creating /content/folder/86/00.  You can see the progress of th= e various threads here:

 

 

This thread i= s not blocked however, but seems to be stuck in a loop, and it is constantl= y running doing something.

 

If you ca= re to look, there's a Yourkit profiling snapshot with this stuck thread her= e:

 

\\ottfs01\users_g\gbuchana\MyTransfer\com.adobe.granite.= quickstart-2012.22-SNAPSHOT-2013-01-11(2).snapshot

 

From the profiler snapshot I captured, it appears to be = stuck in:  org.apache.sling.servlets.post.impl.operations.AbstractCrea= teOperation.deepGetOrCreateNode()

Where it is making a whol= e slew of repeated calls to various things

 

 <= /span>

Looking at the source code for deepGetOrCreateNode(), it would appear = to be stuck in this loop:

 

478    Resource startingResource = =3D null;

479 &nbs= p;  while (startingResource =3D=3D null) {

480      if (startingResourcePath.equals("/")) {=

481        startingResource = =3D resolver.getResource("/");

482     = ; } else if (resolver.getResource(startingResourcePath) !=3D nu= ll) {

483  &n= bsp;     startingR= esource =3D resolver.getResource(startingResourcePath);

484        updateNodeType(resolver, startingR= esourcePath, reqProperties, changes, versioningConfiguration);

485        updateMixins(resolver, st= artingResourcePath, reqProperties, changes, versioningConfiguration);<= /o:p>

486      } else {

487        int pos =3D startingResourcePath.lastI= ndexOf('/');

488 &= nbsp;      if= (pos > 0) {

48= 9         =  startingResourcePath =3D startingResourcePath.substring(0, pos= );

<= span style=3D'font-size:9.0pt;font-family:"Lucida Console"'>490   = ;     } else {

491          starti= ngResourcePath =3D "/";

492      =   }

494    }

 

 

 

Gard= ner Buchanan
Adobe Systems Canada
Office: +1 613 940 3842
Mobile: = +1 613 884 7940

<= o:p> 

= --_000_686848D3189C0845A6E5FA781D6A0FFF373528BDE3nambx03corpad_-- --_005_686848D3189C0845A6E5FA781D6A0FFF373528BDE3nambx03corpad_--