[Sblim-issues] [ sblim-Bugs-3429224 ] Error reusing HTTP-client with JRE 1.6.0_29

[SourceForge.net <no...@so...>]

Bugs item #3429224, was opened at 2011-10-27 02:00
Message generated for change (Comment added) made by yurtsevich
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=712784&aid=3429224&group_id=128809

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: sfcb
Group: None
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: yurtsevich (yurtsevich)
Assigned to: Chris Buccella (buccella)
Summary: Error reusing HTTP-client with JRE 1.6.0_29

Initial Comment:
Hello! 

I met a problem after switching to recent JRE 1.6.0_29. HTTP 501 error "Not Implemented" is raised each time the library tries to reuse previously instantiated HTTP-client. And on the contrary each time the library instantiates new HTTP-client (after previous failed attempt) CIM-request is successful. See attached trace file.

It is possible to configure sblim not to use HTTP clients pool (setting configuration property WBEMConfigurationProperties.HTTP_POOL_SIZE to 0), in this case the library works without errors. But it is a workaround, not fix.

What can you say about that? Is the problem in newest version of JRE or in a way how sblim works with it?

Regards,
Dzmitry Yurtsevich.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-12-18 22:20

Message:
Hello there! Is there anything new about the issue?

----------------------------------------------------------------------

Comment By: Chris Buccella (buccella)
Date: 2011-11-23 05:56

Message:
yurtsevich: no, I'm not currently investigating this, as I have some
higher-priority defects that require my attention.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-22 23:26

Message:
Is there anything new about this problem? By the way I tried JRE1.6.0_30,
which is already available and problem remains.

----------------------------------------------------------------------

Comment By: sum...@gm... (sumitkgaur)
Date: 2011-11-18 04:00

Message:
Like yurtsevich said ... If socket is explicitly closed after each request
no 501 errors are raised. I have verified in my setup also and it works.
But question still remain unanswered, Which http field is flaged and
creating problem with JRE1.6U29 onwards .. or .. is it is a correct  from
JRE point of view and CIMOM is having problem with some HTTP
field/behaviour. 

----------------------------------------------------------------------

Comment By: sum...@gm... (sumitkgaur)
Date: 2011-11-16 22:05

Message:
Hi
I had faced similar issue. 
Setup used:   
client : JAVA Test client with cimclient.jar on my laptop(windows) with
JRE1.6 update 29.
server: SFCB server

1)	We have not observed any problem with JRE1.6 update 26 with same setup.
2)	We have also observed  while snooping network packets that request is
failing with HTTP 501 error for HTTP1.1 and get through for HTTP1.0 . We
have observed this for port 5988 port (http - non secure) and JRE1.6 update
29.
4)	 Also same is not happening with https(secure) requests. 
5)	We tried to run tests with forced HTTP1.0 and JREU29. Some requests
works but there are still failure randomly.

** Also same client setup works fine with other CIMOM like OpenPegasus.




----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-16 06:00

Message:
And one more note. Probably this is pretty obvious but still... Problem is
not in reusing HttpClient as stated in this thread's header but in reusing
socket which is encapsulated in HttpClient. If socket is explicitly closed
after each request no 501 errors are raised.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-16 01:49

Message:
I've installed last update on our ESXi 4.1 (ESXi_4.1_update02, 10/27/2011)
and this didn't help.

----------------------------------------------------------------------

Comment By: Chris Buccella (buccella)
Date: 2011-11-14 07:57

Message:
Ah, it's on ESXi.  You should check with VMWare on this; they have some
patches on top of the stock version of SFCB. Something there might be
affecting behavior (I'm not blaming them for sure, but it's a possibility).

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-14 00:01

Message:
I have an update concerning conditions when problem occurs. I've just
tested our client with ESXi 5 server (previously it was ESXi 4) and problem
with errors 501 occurs there not only using JRE 1.6.0_29, but also using
previous versions, e.g. JRE 1.6.0_18.

And another problem with ESXi 5. enumerateInstance requests fail sometimes
with very strange "WBEMException: CIM_ERR_FAILED (HTTP 200 - OK)" error,
even with previously found workaround (with zero pool).

It's just terrible. :)

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-10 04:41

Message:
No, nothing was changed at server side. Just switching JREs on the same
client polling the same server: with JRE 1.6.0_18 client is working without
any problems, with JRE 1.6.0_29 - with 501 errors.

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-11-10 04:23

Message:
Just checking that sfcb was NOT updated at the same time you updated JRE,
correct?

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-11-09 14:11

Message:
I have passed most of the pertinent information on to the sfcb team for
analysis and assistance.  The most curious thing about sfcb_HTTP_trace.txt
is that the HTTP 501 error logging is almost immediately followed by
logging of the HTTP headers, where the first one is POST:

[1] [11/09/2011 10:58:21] 5807082/0xffb85a60 ---
/build/mts/release/bora-334313/oss-cim/common/..//sfcb/1.3.4/httpAdapter.c(926)
: --- Header: POST

while in httpAdapter.c, the only way that 501 is generated is if the method
is not POST.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-09 01:21

Message:
On our site is sfcb of version 1.3.4. I also attached sfcb-trace of HTTP
processing. 

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-11-08 09:21

Message:
P.S. You might want to see if sfcb tracing can provide any details, see
https://sourceforge.net/apps/mediawiki/sblim/index.php?title=SFCB_Debugging

For this case, start with -t 8

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-11-08 08:51

Message:
The Java CIM Client creates sockets, reads/writes data, etc. but they are
all Java API calls so it is the JRE doing the actual grunt work and that is
apparently the only thing that changed between success and failure,
correct?

Also, the sfcHttpd server indicates that sfcb is the CIMOM - what version
are you using there?  It would help to have the sfcb folks tell us why
there daemon is returning 501 in the first place.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-07 23:16

Message:
I am not absolutely sure if I got everything right, but looks like in case
of success response-header is:

HTTP/1.1 200 OK
Content-Type: application/xml; charset="utf-8"
Cache-Control: no-cache
CIMOperation: MethodResponse
Transfer-encoding: chunked
Trailer: CIMError, CIMStatusCode, CIMStatusCodeDescription

and in case of 501 error:

HTTP/1.1 501 Not Implemented
Content-Length: 0
Server: sfcHttpd

Our application is Java-application, but it does not manage
connections/sockets, at least explicitly, sblim inside of itself does it,
or I am wrong?

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-11-07 02:52

Message:
Really need to see the HTTP header of the responses, perhaps there is some
indication in them of what's not implemented.

However, being able to incorporate a delay in sending requests to
workaround the issue sure makes it seem like there's a problem with the
receiving socket, i.e. unable to handle more than one request per second.

What is handling the receiving socket?  Is it a Java app?

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-03 03:13

Message:
Unfortunately I could not manage to connect our application to our server
through ECUTE Analyzer. It fails with "connection refused". I tried all
possible configurations but without success. The only way I managed to get
something from Analyzer is to run Explorer using Analyzer session. But the
result in this case is different than running our application, i.e. there
were no 501 error at all. Among previously attached files it's
analyzer_JRE1.6.0_29.zip and analyzer_JRE1.6.0_18.zip.

But as I didn't manage to use Analyzer I tried to dig into sblim sources
and tried to debug them stopping in certain places to see variables values.
And interesting thing - everything worked!!! You know why? Because of
delays - program stopped before next request at breakpoints. So, I removed
breakpoints and put:

            try {
                Thread.sleep(1000);
            } catch (InterruptedException e) {
            }

into WBEMClientCIMXML.transmitRequest() at line 1701 (2.1.6 version of
sblim) before

			connection = newConnection(pCimMethod, pHeader, useMPost);

and again it worked without 501 errors! Delay less than 1 second though
brings 501 errors sometimes.

So, there are 2 workarounds so far: 1. to use new HttpClient for each
request without pool; 2. forcing quite long delay between requests.

By the way, debugging sblim I managed to pick up HTTP Headers. In both
cases (in success and with 501 error) they are the same:

POST /cimom HTTP/1.1
Connection: Keep-alive
Content-type: application/xml; charset="utf-8"
Content-Language: en-GB
CIMMethod: Associators
CIMOperation: MethodCall
Authorization: Basic cm9vdDpRd2VydHkhMQ==
Content-length: 763
CIMProtocolVersion: 1.0
TE: trailers
CIMObject: root/svs
Accept-Language: en-GB, *
Host: 192.168.116.171
Cache-Control: no-cache
Accept: text/html, text/xml, application/xml

What would you suggest? I have still no idea what to do.

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-11-02 13:45

Message:
What I was referring to in my last comment was to use ECUTE Analyzer to
capture the HTTP communication between the Java CIM Client and CIMOM.  I
downloaded all the new attachments and don't see it in there offhand, but I
haven't looked through them all thoroughly.  Did I miss it?

To see if this is a client issue, I need to see what is in the header and
payload of the HTTP 501 response, but ideally all four of the following:
1) HTTP request that generates HTTP 200
2) HTTP 200 response
3) HTTP request that generates HTTP 501
4) HTTP 501 response

If both requests are the same and the only difference is 1st vs 2nd use of
socket, then that seems like an issue with whoever is managing the server
socket (CIMOM? JRE?) and not the Client/.  If the Client is sending
different requests, then that seems like an issue with the Client.

The setup is easy, if your app is normally connecting to
http://1.2.3.4:5988 then set the Analyzer's server connection to that, set
the client connection to some unused port on the local machine (i.e. 5999)
and then have your app connect to that (http://localhost:5999).  If THAT
hangs, then there may also be an issue with ECUTE.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-11-02 05:38

Message:
I've gathered all possible information. Sorry for many attachments,
probably not all of them are indeed needed but who knows. Those big ones
were zipped by me cause otherwise tracker system rejected to upload them.

So, what I've done. I've made requests to the 6 same CIM-classes from ECUTE
Explorer running it with and without Analyzer session and all this first
with JRE 1.6.0_18 and then with JRE 1.6.0_29.

What I found out first was that the result was different depending on
whether there was Analyzer session or not. On both JREs each second
CIM-request hanged while using Analyzer session. I have no idea why.
Second, without Analyzer session, on JRE 1.6.0_18 all requests were
successful, on JRE 1.6.0_29 - all unsuccessful.

I hope description of each file is clear enough.

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-11-01 20:44

Message:
Since you are familiar with ECUTE, could you please use the Analyzer to
capture the HTTP request and response for both the 501 and 200 case.  I am
really at a loss here from the Client's perspective, especially if the
request is the same for both success and failure.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-10-31 00:21

Message:
Unfortunately disabling MPOST didn't help (see attached trace file). First
request is processed successfully using POST but second fails just as
before.

By the way, probably this helps. eCute CIM-explorer also fails to request
CIM-data with JRE 1.6.0_29 (see attached screenshots).

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-10-28 09:38

Message:
From the Java CIM Client point-of-view, the only special logic performed
when HTTP 501 is received is the following:

if (no CIMProtocolVersion HTTP header field && 
....no CIMError HTTP header field && 
....M-POST enabled) {
...disable M-POST for 24hrs
...retry with POST
}

This is indeed happening as indicated by the following trace file entry:

"Received HTTP Error 501 - HTTP NOT IMPLEMENTED - falling back to HTTP
POST"

and is why the initial "HTTP Operation=" in the trace file is M-POST while
all of the rest are POST.  However, the HTTP 501 errors still occur with
POST so this should not be the issue UNLESS the initial M-POST just messes
up all future socket connections as well - note that this is the only time
HTTP 501 occurs on a socket's first use.  To see if this is the case,
please set the sblim.wbem.httpMPOST property to false and retry.

----------------------------------------------------------------------

Comment By: yurtsevich (yurtsevich)
Date: 2011-10-27 23:53

Message:
Sorry, indeed it was initially a trace file from a variant with the
workaround. I've attached a trace file with the error.

Before switching to JRE 1.6.0_29 I was using 1.6.0_18. And I can definitely
say that the same application (same our code + same sblim version 2.1.6)
works with 1.6.0_18 and does not work (HTTP 501 errors) with 1.6.0_29.
Upgrading to the latest 2.1.10 version of sblim does not help. Analyzing
responses from QA team I may assume that the problem occurs also using JRE
1.6.0_25.

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-10-27 12:23

Message:
The attached trace file must be with the HTTP_POOL_SIZE=0 workaround, all I
see is an initial HTTP 401 and then the rest are HTTP 200 responses.  Can
you please attach a trace file that includes the HTTP 501 responses...

Are you implying that this worked fine before, but after upgrading to JRE
1.6.0_29 it began failing?  If so, on what version of JRE was it working?

Without additional information, the only reason I can think of for getting
a 501 now is that there is an HTTP field that was previously being ignored
but now is being flagged as an error with the updated JRE (assuming
everything else is the same)...

----------------------------------------------------------------------

Comment By: Dave Blaschke (blaschke-oss)
Date: 2011-10-27 04:58

Message:
Reassigning categories, Java Client is the sunset 1.x code stream

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=712784&aid=3429224&group_id=128809