S3 Hangs, no details

[Philippe Laflamme]

Hi,

I'm using jclouds to interact with AWS. So far, I'm successfully using
EC2: launching instances, creating new ones, issuing SSH commands,
etc. Very easy with jclouds, thanks!

Now, I'm trying to add an S3 component to my app and I can't get it to
work. Whenever my app makes a query to S3, it just waits for a
response that seems to never come back and then times out. I don't see
what I'm doing wrong and I'm not sure what the problem is (probably
not jclouds at all).

Here's my setup code:

context = new BlobStoreContextFactory().createContext("aws-s3",
AWS_KEY, AWS_SECRET, ImmutableSet.<Module> of(new
Log4JLoggingModule()))

and my call to S3:

if(context.getBlobStore().containerExists(BUCKET_NAME) == false) {
context.getBlobStore().createContainerInLocation(null, BUCKET_NAME);
}

Here's the log:

TRACE - ernal.AsyncRestClientProxy - Converting
AWSS3AsyncClient.getObject
TRACE - al.RestAnnotationProcessor - looking up default endpoint for
[class=S3AsyncClient, method=getObject, args=[XXX, YYY,
[Lorg.jclouds.http.options.GetOptions;@369a9f38]]
TRACE - al.RestAnnotationProcessor - using default endpoint
https://s3.amazonaws.com for [class=S3AsyncClient, method=getObject,
args=[XXX, YYY, [Lorg.jclouds.http.options.GetOptions;@369a9f38]]
TRACE - al.RestAnnotationProcessor - adding filter
org.jclouds.s3.filters.RequestAuthorizeSignature@614b3189 from
annotation on org.jclouds.aws.s3.AWSS3AsyncClient
TRACE - ernal.AsyncRestClientProxy - Converted
AWSS3AsyncClient.getObject to GET https://org.obiba.datashield.s3.amazonaws.com/methods.xml
HTTP/1.1
TRACE - ernal.AsyncRestClientProxy - Response from
AWSS3AsyncClient.getObject is parsed by
ParseObjectFromHeadersAndHttpContent
DEBUG - ernal.AsyncRestClientProxy - Invoking
AWSS3AsyncClient.getObject
TRACE - ernal.AsyncRestClientProxy - Exceptions from
AWSS3AsyncClient.getObject are parsed by ReturnNullOnKeyNotFound

And then it times out.

Anyone know what I'm doing wrong?

Thanks,
Philippe

[Adrian Cole]

Hi, Philippe.

from the log, it seems the last command was
getBlob("org.obiba.datashield", "methods.xml"). Does this look right
to you?

You can also setup a log file with TRACE output for category
"jclouds.headers" for an easier to see view of http traffic going out
and back.

Cheers,
-Adrian

> --
> You received this message because you are subscribed to the Google Groups "jclouds" group.
> To post to this group, send email to jcl...@googlegroups.com.
> To unsubscribe from this group, send email to jclouds+u...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/jclouds?hl=en.
>
>

[Philippe Laflamme]

Oops! meant to hide that... oh well! ;)

Yep, I want to access some file (methods.xml) in the
"org.obiba.datashield" bucket. Is that the way to go about it?

I used the AWS REST client and it works (no timeout issues).

Here's the output of jcoulds.headers:

DEBUG - jclouds.headers - >> GET
https://org.obiba.datashield.s3.amazonaws.com/methods.xml HTTP/1.1
DEBUG - jclouds.headers - >> Host:
org.obiba.datashield.s3.amazonaws.com
DEBUG - jclouds.headers - >> Date: Tue, 19 Jul 2011
01:20:06 GMT
DEBUG - jclouds.headers - >> Authorization: AWS <BASE64
signature>

> >https://s3.amazonaws.comfor [class=S3AsyncClient, method=getObject,

> > args=[XXX, YYY, [Lorg.jclouds.http.options.GetOptions;@369a9f38]]
> > TRACE - al.RestAnnotationProcessor - adding filter
> > org.jclouds.s3.filters.RequestAuthorizeSignature@614b3189 from
> > annotation on org.jclouds.aws.s3.AWSS3AsyncClient
> > TRACE - ernal.AsyncRestClientProxy - Converted

> > AWSS3AsyncClient.getObject to GEThttps://org.obiba.datashield.s3.amazonaws.com/methods.xml

[Adrian Cole]

Hi, Phillipe.

I'm a bit stumped.. can you setup a test bucket and add/get a blob
with jclouds to this? Maybe there's something subtle to the existing
bucket you have. What region is it in? I presume you are using
version 1.0.0?

Cheers,
-Adrian

[Philippe Laflamme]

I tried renaming the bucket, no luck. I also tried to make the bucket public, still no luck (try the obiba-test bucket).

Here's the stack dump during the waiting period:

"btpool0-2" prio=10 tid=0x00007f09083bd000 nid=0x42e7 waiting on condition [0x00007f090291d000]

   java.lang.Thread.State: TIMED_WAITING (parking)

at sun.misc.Unsafe.park(Native Method)

- parking to wait for  <0x00000000e41cd8b8> (a java.util.concurrent.FutureTask$Sync)

at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037)

at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1326)

at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:257)

at java.util.concurrent.FutureTask.get(FutureTask.java:119)

at org.jclouds.concurrent.config.ExecutorServiceModule$AddToStringFuture.get(ExecutorServiceModule.java:234)

at com.google.common.util.concurrent.ForwardingFuture.get(ForwardingFuture.java:70)

at com.google.common.util.concurrent.Futures$ChainingListenableFuture.get(Futures.java:647)

at org.jclouds.concurrent.ExceptionParsingListenableFuture.get(ExceptionParsingListenableFuture.java:74)

at org.jclouds.concurrent.internal.SyncProxy.invoke(SyncProxy.java:130)

at $Proxy91.getObject(Unknown Source)

at org.jclouds.s3.blobstore.S3BlobStore.getBlob(S3BlobStore.java:221)

        ...

Any ideas?

[Philippe Laflamme]

I created a test to reduce the amount of unnecessary stuff around the problem. The result is that I can access S3, no issues. So the problem is when I deploy within my development environment.

After poking around, I found that I've got two threads that seem to be deadlocking. Here's the situation:

A request comes in the app, which triggers Guice to instantiate an object (lazy singleton). That instance has a dependency on the BlobStoreContext and uses it to lookup a bucket. By doing so, it triggers an http request that jclouds makes a Future out of. This Future is executed in another thread which itself uses Guice to resolve a dependency. The second thread seems to block within Guice, probably because the first thread is still creating the requested instance. Here are the relevant stacks:

Web request thread (this thread is creating an instance through GWT): http://pastebin.com/DpVNu0M6

Future execution thread: http://pastebin.com/C2hN6F54

Notice that the second thead is blocked on the com.google.inject.internal.InternalInjectorCreator lock which is held by the first thread.

I'll try making an eagerSingleton() see if that fixes the issue...

Philippe

[Andrew Phillips]

> A request comes in the app, which triggers Guice to instantiate an object
> (lazy singleton). That instance has a dependency on the BlobStoreContext and
> uses it to lookup a bucket. By doing so, it triggers an http request that
> jclouds makes a Future out of. This Future is executed in another thread
> which itself uses Guice to resolve a dependency. The second thread seems to
> block within Guice, probably because the first thread is still creating the
> requested instance. Here are the relevant stacks:
>
> Web request thread (this thread is creating an instance through GWT):
> http://pastebin.com/DpVNu0M6
> Future execution thread: http://pastebin.com/C2hN6F54
>
> Notice that the second thead is blocked on
> the com.google.inject.internal.InternalInjectorCreator lock which is held by
> the first thread.
>
> I'll try making an eagerSingleton() see if that fixes the issue...

It looks like you may have run into:

http://code.google.com/p/google-guice/issues/detail?id=183

Quote from that: "For what it's worth, Guice is not happy when you
start threads in injected members."

-- "[the] constructor need not start any thread -- but simply to
communicate (directly or indirectly) with one"

...and it looks as though the S3 call in your constructor is going
that by handing off the request to an ExecutorService.

ap

[Philippe Laflamme]

I just fixed the problem by not doing the S3 call within my constructor.

Thanks Adrian, that's precisely the issue I hit...

Philippe

--

You received this message because you are subscribed to the Google Groups "jclouds" group.
To post to this group, send email to jcl...@googlegroups.com.

To unsubscribe from this group, send email to jclouds+unsubscribe@googlegroups.com.

[Tim Peierls]

I just added the following note to that Guice issue (183):

Another way out is to use the approach described here:
http://tembrel.blogspot.com/2009/11/concurrently-initialized-singletons-in.html

It doesn't exactly solve the problem, but it pushes it to a different place where it might be easier to cope with.

--tim

To unsubscribe from this group, send email to jclouds+u...@googlegroups.com.

[Adrian Cole]

Hi, Philippe.

Glad things are working, but I don't get credit here.. Andrew does :D

Cheers,
-A

>> jclouds+u...@googlegroups.com.

>> For more options, visit this group at
>> http://groups.google.com/group/jclouds?hl=en.
>>
>

> --
> You received this message because you are subscribed to the Google Groups
> "jclouds" group.
> To post to this group, send email to jcl...@googlegroups.com.
> To unsubscribe from this group, send email to

> jclouds+u...@googlegroups.com.

[Adrian Cole]

Thanks for the notes, Tim. I've entered a case to help us improve our
scope usage over time.

http://code.google.com/p/jclouds/issues/list?thanks=630

Cheers,
-Adrian