12:32 a.m.
[
https://jira.jboss.org/jira/browse/DNA-616?page=com.atlassian.jira.plugin...
]
Randall Hauch updated DNA-616:
------------------------------
Attachment: DNA-616_fix.patch
The problem has to do with the fact that this example uses a FederatedRepositorySource as
a source for a JpaRepository (which creates a FederatedRepositorySource on top of the
supplied source). Thus, there is a FederatedRepositorySource that uses another
FederatedRepositorySource, and this is the condition that causes the deadlock.
When the JcrRepository is created, it uses a SearchIndexer to crawl the content and create
the requisite indexes for query/search. The SearchIndexer is create a
CompositeRequestChannel (which it uses to submit to the designated repository source a
CompositeRequest that remains open, allowing the SearchIndexer to supply requests and then
use those requests to build other requests that are submitted within the same
execution/transaction), and is submitting a ReadBranchRequest to the source that happens
to be the lower FederatedRepositorySource. The FederatedRepositorySource returns a
connection that has an execute(...) method that implements the work by using the fork-join
algorithm to process the request, which in this case is the CompositeRequest (owned by
the CompositeRequestChannel created by the SearchIndexer).
Now, the ForkRequestProcessor works on all the incoming request, which again is the
CompositeRequest. The FRP's process(CompositeRequest) is actually inherited from
RequestProcessor, and simply uses an iterator to get all of the requests within the
CompositeRequest. The iterator promptly returns the first ReadBranchRequest, so the
ForkRequestProcessor handles this via it's process(ReadBranchRequest), and like all of
the ForkRequestProcessor.process(...) methods, forks the request into appropriate requests
to submit to the underlying (federated) sources, and then it enqueues the forked requests
into a queue.
Note that the ForkRequestProcessor does NOT mark the requests it processes as being
completed. After all, this is the job of the JoinRequestProcessor.
Meanwhile, the ForkRequestProcessor.process(ReadBranchRequest) completes and returns, and
the iterator in the ForkRequestProcessor.process(CompositeRequest) then attempts to get
the next request.
But the SearchIndexer has only added one ReadBranchRequest and is waiting/blocking until
that request is completed before it continues. But the FederatedRepositoryConnection is
waiting/blocking until the next request is added to the CompositeRequest. Thus the
deadlock.
The only way to break this deadlock is for the ReadRequestBranch to be completed. But,
because of the way that FederatedRepositoryConnection.execute(...) is implemented, the
ForkRequestProcessor.process(request) must complete before the JoinRequestProcessor is
started. So we need to create and start the JoinRequestProcessor without waiting for the
ForkRequestProcessor.process(request) to complete.
The solution is actually coded in the FederatedRepositoryConnection.execute(...) - there
is a 'shouldProcessSynchronously(Request)' method that returns whether the
ForkRequestProcessor should be processed synchronously or asynchronously, and is
implemented to always return 'true' (synchronous). The solution to this problem
requires that the method return 'false' for CompositeRequests that contain more
than one (or an unknown number) of requests. (In other cases, there is just one request,
so the forking can be done synchronously, saving the work of pushing the fork processing
into the executor service.)
Thus, the 'shouldProcessSynchronously(Request)' was implemented to do this, and
the test completed ... with an error. This error is caused by a bug in the
JoinRequestProcessor.process(ReadBranchRequest) that failed to properly calculate the
projected actual Locations for the ProxyNodes from the source requests. (Apparently the
SearchIndexer reads a branch that is deeper than was previously tested.)
Fixing the JoinRequestProcessor.process(ReadBranchRequest) allows the repository example
test cases to complete successfully.
See the attached patch, which was committed and verified with a full integration build
(all unit and integration tests pass). The patch also changes the log level of the
repository example back to 'ERROR' (what it was previously), and also re-enables
the 'docs/examples/gettingstarted/repository' project in the
'docs/examples/gettingstarted/pom.xml'.
JPA connector pooling doesn't appear to shutdown
------------------------------------------------
Key: DNA-616
URL: https://jira.jboss.org/jira/browse/DNA-616
Project: DNA
Issue Type: Bug
Components: Connectors
Affects Versions: 0.7
Reporter: Randall Hauch
Assignee: Randall Hauch
Priority: Blocker
Fix For: 0.7
Attachments: DNA-616_fix.patch
Our integration tests now appear to be running forever in what appears to be an infinite
loop. The unit tests in 'docs/examples/gettingstarted/repositories' module appear
to run forever, with the log ending with the snippet below (which goes on forever). Note
that the example is running with DEBUG (which also needs to be changed).
02:16:42,310 DEBUG
org.jboss.dna.connector.store.jpa.model.simple.NodeEntity{referentialIntegrityEnforced=false,
childName=Learjet 45,
childNamespace=org.jboss.dna.connector.store.jpa.model.common.NamespaceEntity#1,
compressed=null, id=5, allowsSameNameChildren=false, largeValues=<uninitialized>,
propertyCount=11,
data=2c6d8085f7848080808af480a7fbe8f4f4f0baafaff7f7f7aeeae3f0aeeff2e7afeae3f2afb1aeb0fdf0f2e9ede1f2f9d4f9f0e5f7868080808180cef480b8fbe8f4f4f0baafaff7f7f7aeeae2eff3f3aeeff2e7afe4eee1afe5f8e1edf0ece5f3afe1e9f2e3f2e1e6f4afb1aeb0fdc1e9f2e3f2e1e6f4f4808ae9eef4f2efe4f5e3e5e4f7868080808180d3f48084b1b9b9b5f48084e3f2e5f7f7868080808180d3f48081b2f48085ede1ebe5f2f7868080808180d3f48087cce5e1f2eae5f4f48085edefe4e5ecf7868080808180d3f48084cccab4b5f4808be3f2f5e9f3e5d3f0e5e5e4f7868080808180d3f48085b4b5b7ebf4f48083f5f2ecf7868080808180d3f480a7e8f4f4f0baafafe5eeaef7e9ebe9f0e5e4e9e1aeeff2e7aff7e9ebe9afcce5e1f2eae5f4dfb4b5f48085f2e1eee7e5f7868080808180d3f48086b2b1b2b0eeedf4808beef5ede2e5f2c2f5e9ecf4f7868080808180d3f48084b2b6b4abf4808be5edf0f4f9d7e5e9e7e8f4f7868080808180d3f48087b1b3b6b9b5ece2,
sameNameSiblingIndex=1, indexInParent=1,
nodeUuidString=6ae6cf0c-88b8-4cb9-af63-195a6a351378, children=<uninitialized>,
parent=org.jboss.dna.connector.store.jpa.model.simple.NodeEntity#3, workspaceId=1}
02:16:42,310 DEBUG more......
02:16:42,310 DEBUG about to open PreparedStatement (open PreparedStatements: 0, globally:
0)
02:16:42,310 DEBUG
delete
from
DNA_SUBGRAPH_NODES
where
QUERY_ID=?
02:16:42,311 DEBUG cxnStmtMgr.statementSet( org.hsqldb.jdbc.jdbcConnection@588a137c
).size(): 15
02:16:42,311 DEBUG checkoutStatement:
com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 15; checked out:
1; num connections: 1; num keys: 15
02:16:42,311 DEBUG about to close PreparedStatement (open PreparedStatements: 1,
globally: 1)
02:16:42,312 DEBUG checkinStatement():
com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 15; checked out:
0; num connections: 1; num keys: 15
02:19:41,831 DEBUG Checking for expired resources - Fri Jan 01 02:19:41 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:19:41,831 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:19:41,831 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:19:41,831 DEBUG Refurbishing idle resources - Fri Jan 01 02:19:41 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:19:41,831 DEBUG trace com.mchange.v2.resourcepool.BasicResourcePool@427a39ea [managed:
1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@2ac6fb1)
02:20:26,832 DEBUG Checking for expired resources - Fri Jan 01 02:20:26 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:20:26,832 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:20:26,832 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:21:11,835 DEBUG Checking for expired resources - Fri Jan 01 02:21:11 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:21:11,835 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:21:11,835 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:21:56,837 DEBUG Checking for expired resources - Fri Jan 01 02:21:56 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:21:56,837 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:21:56,837 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:22:41,834 DEBUG Refurbishing idle resources - Fri Jan 01 02:22:41 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:22:41,834 DEBUG trace com.mchange.v2.resourcepool.BasicResourcePool@427a39ea [managed:
1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@2ac6fb1)
02:22:41,838 DEBUG Checking for expired resources - Fri Jan 01 02:22:41 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:22:41,838 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:22:41,838 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:23:26,840 DEBUG Checking for expired resources - Fri Jan 01 02:23:26 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:23:26,840 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:23:26,840 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:24:11,843 DEBUG Checking for expired resources - Fri Jan 01 02:24:11 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:24:11,843 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:24:11,843 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:24:56,845 DEBUG Checking for expired resources - Fri Jan 01 02:24:56 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:24:56,845 DEBUG BEGIN check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:24:56,845 DEBUG FINISHED check for expired resources.
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:25:41,837 DEBUG Refurbishing idle resources - Fri Jan 01 02:25:41 EST 2010
[com.mchange.v2.resourcepool.BasicResourcePool@427a39ea]
02:25:41,837 DEBUG trace com.mchange.v2.resourcepool.BasicResourcePool@427a39ea [managed:
1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@2ac6fb1)
and so on.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
https://jira.jboss.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira