Debugging HTTP classes?

Posted by Tim Kuehn on 04-Feb-2016 16:43

I'm trying to use the HTTP classes to do a REST client to a local Neo4j server and I'm having difficulties with the classes not deciphering the json that's being returned and telling me that I have an empty message (content length = 0) and the json is {}.

The docs I'm using are here: https://documentation.progress.com/output/oehttpclient/index.html

I haven't found anything in these docs that would enable me to get debugging information from the classes, or get them to output the contents of the return message so I can try and decipher why I'm netting a return result. 

The REST message I expect is coming back is this:

HTTP/1.1 200 OK
Date: Thu, 04 Feb 2016 20:06:01 GMT
Content-Type: application/json; charset=UTF-8
Access-Control-Allow-Origin: *
Content-Length: 744
Server: Jetty(9.2.z-SNAPSHOT)

{
  "extensions" : { },
  "node" : "localhost:7474/.../node",
  "node_index" : "localhost:7474/.../node",
  "relationship_index" : "localhost:7474/.../relationship",
  "extensions_info" : "localhost:7474/.../ext",
  "relationship_types" : "localhost:7474/.../types",
  "batch" : "localhost:7474/.../batch",
  "cypher" : "localhost:7474/.../cypher",
  "indexes" : "localhost:7474/.../index",
  "constraints" : "localhost:7474/.../constraint",
  "transaction" : "localhost:7474/.../transaction",
  "node_labels" : "localhost:7474/.../labels",
  "neo4j_version" : "2.3.1"
}

What's strange is if I point my test program at Telerik "StarWars" REST server, I get json results I could have my program take apart.

As far as I can see, the only difference is that the StarWars RESTserver returns the json all in one line while my Neo4j server returns one line for each variable. 

All Replies

Posted by Peter Judge on 05-Feb-2016 08:32

In 11.6.0+ you set log-manager:log-level to 5+ . It creates some files in your session:temp-dir

In 11.5.+ you use session:debug-alert for the same purpose.

Posted by Tim Kuehn on 05-Feb-2016 12:27

That helped.

Now for the puzzle - this is what the HTTP class sent:

GET /db/data/ HTTP/1.1
User-Agent: OpenEdge-HttpClient/0.3.0 (WIN32/64) OpenEdge/11.6.0.0.1233 Lib-ABLSockets/0.3.0
Host: localhost:7474
Accept: application/json

and this is the response it logs as having gotten back:

HTTP/1.1 200 OK
Date: Fri, 05 Feb 2016 18:12:44 GMT
Content-Type: application/json; charset=UTF-8
Access-Control-Allow-Origin: *
Content-Length: 744
Server: Jetty(9.2.z-SNAPSHOT)

This header indicates 744 bytes in the body of the message - which is correct. The log file shows the header followed by 8K of NULs in the file.

This is what came out in the trace file - the READ and WRITE counts correspond to the headers only, the return data content is not logged as being transferred:

[16/02/05@13:17:18.166-0500] P-176952 T-176792 1 4GL -- Logging level set to = 2
[16/02/05@13:17:18.166-0500] P-176952 T-176792 1 4GL -- No entry types are activated
[16/02/05@13:17:18.167-0500] P-176952 T-176792 1 4GL -- Logging level set to = 5
[16/02/05@13:17:18.356-0500] P-176952 T-176792 1 4GL HTTPCLIB REQUEST: FILE= D:\tmp\Json\tmp\request-raw.txt
[16/02/05@13:17:18.359-0500] P-176952 T-176792 1 4GL HTTPCLIB RESPONSE: FILE= D:\tmp\Json\tmp\response-data-received.txt
[16/02/05@13:17:18.361-0500] P-176952 T-176792 1 4GL SOCKET CONNECT: -H localhost -S 7474
[16/02/05@13:17:19.321-0500] P-176952 T-176792 1 4GL SOCKET CONNECT: TIME(ms)=959
[16/02/05@13:17:19.322-0500] P-176952 T-176792 1 4GL SOCKET WRITE: TIME(ms)=0
[16/02/05@13:17:19.322-0500] P-176952 T-176792 1 4GL SOCKET WRITE: SIZE(b)=168
[16/02/05@13:17:19.329-0500] P-176952 T-176792 1 4GL SOCKET READ: AVAIL(b)=187
[16/02/05@13:17:19.329-0500] P-176952 T-176792 1 4GL SOCKET READ: TIME(ms)=0
[16/02/05@13:17:19.329-0500] P-176952 T-176792 1 4GL SOCKET READ: SIZE(b)=187
[16/02/05@13:17:19.330-0500] P-176952 T-176792 1 4GL HTTPCLIB CHUNK: NUM= 1
[16/02/05@13:17:19.330-0500] P-176952 T-176792 1 4GL HTTPCLIB CHUNK: SIZE(b)= 8192
[16/02/05@13:17:19.330-0500] P-176952 T-176792 1 4GL HTTPCLIB CHUNK: READ(b)= 187
[16/02/05@13:17:19.352-0500] P-176952 T-176792 1 4GL SOCKET READ: COMPLETE= yes
[16/02/05@13:17:19.352-0500] P-176952 T-176792 1 4GL SOCKET READ: ERROR= ?
[16/02/05@13:17:19.352-0500] P-176952 T-176792 1 4GL SOCKET READ: TOTAL TIME(ms)=28
[16/02/05@13:17:19.389-0500] P-176952 T-176792 1 4GL ---------- Log file closed at user's request

Posted by Tim Kuehn on 05-Feb-2016 12:31

Another difference is the GET format - the SoapUI tool sends this:

GET http://localhost:7474/db/data/ HTTP/1.1

The HTTP class sends this:

GET /db/data/ HTTP/1.1

So the difference is the HTTP class is webserver relative while the SoapUI tool is fully pathed.

Posted by Peter Judge on 05-Feb-2016 12:38

The 8k-n of nulls is correct - the txt files are simply dumps of the packets received (which are a max of 8k).

There is a bug (PSC00344734: HTTP Client fails with NIO) where basically the server sends the headers in one 8k packet and the data in another and the http client is a little over-enthusiastic in deciding whether the response was complete or not. This bug will be fixed in all upcoming releases (incl 11.6 service packs) and shouldn't be too hard to hotfix if needed (you'll have to contact TS for that).

Posted by Tim Kuehn on 05-Feb-2016 12:38

Is there a way to force the GET to use a fully-qualified address?

Posted by Peter Judge on 05-Feb-2016 12:40

That's most likely because the SoapUI is using a proxy.

Posted by Peter Judge on 05-Feb-2016 12:42

[quote user="Tim Kuehn"]

Is there a way to force the GET to use a fully-qualified address?

[/quote]

On the RequestBuilder or the ClientBuilder , add ViaProxy() but I don't believe this is the issue (see earlier post)

Posted by Tim Kuehn on 05-Feb-2016 12:46

[quote user="Peter Judge"] There is a bug (PSC00344734: HTTP Client fails with NIO) ... and shouldn't be too hard to hotfix if needed (you'll have to contact TS for that).  [/quote]

I have a TS case open - 00337228. I think they're trying to figure out where to route it to.

Who would I ping for the hotfix?

Posted by Peter Judge on 05-Feb-2016 12:59

If you give the TSE that bug number it should get to the right person/group.

Posted by Tim Kuehn on 05-Feb-2016 13:00

I've added it to the case.

This thread is closed