Thread Rating:
  • 0 Votes - 0 Average
  • 1
  • 2
  • 3
  • 4
  • 5
Reason for error on Sync call...
06-07-2012, 08:49 AM
Post: #1
Reason for error on Sync call...
I am making a Sync call from a generated proxy which returns -1 and this error message:

Quote:------------------------------
SequenceNumber: 1
Service: urn:schemas-upnp-org:service:ChannelServices:1
Action: ChannelList_getAsJson
ErrorLevel: HTTP
ErrorCode: 1
ErrorDescription: Unknown
------------------------------

How do I find out the meaning of the error code? I suspect that the Sync call has a timeout which is occurring, but I don't know the value of that timeout. Do you think that the Sync calls could take a timeout value as a parameter?

I understand that I should probably be using async calls to the Upnp device, but I want to keep things simple in the first instance and just have a blocking RPC. One of the reasons that OhNet looks promising is that there is an API ready to make blocking calls and there is no need to implement timeouts and concurrent calling myself.

Any advice you can offer is welcome...

Doug

BTW: The proxy generated by OhNetGen contained dash characters in both function and variable names which are invalid for names in the C language! I replaced all of the dashes in names with underscores.
Find all posts by this user
06-07-2012, 09:37 AM
Post: #2
RE: Reason for error on Sync call...
(06-07-2012 08:49 AM)dough Wrote:  I am making a Sync call from a generated proxy which returns -1 and this error message:

Quote:------------------------------
SequenceNumber: 1
Service: urn:schemas-upnp-org:service:ChannelServices:1
Action: ChannelList_getAsJson
ErrorLevel: HTTP
ErrorCode: 1
ErrorDescription: Unknown
------------------------------

How do I find out the meaning of the error code? I suspect that the Sync call has a timeout which is occurring, but I don't know the value of that timeout. Do you think that the Sync calls could take a timeout value as a parameter?

I'm afraid you'll have to add logging to ohNet to get more detailed info. I'd imagine the error is being thrown from InvocationUpnp::Invoke (OpenHome/Net/ControlPoint/Upnp). You could start by adding
Code:
iSocket.LogVerbose(true);
This'll log the request and any response to stderr (or whatever alternative location you setup in OhNetInitParamsSetLogOutput).

I'd guess this'll show that the exception comes from InvocationUpnp::ReadResponse being unhappy with something about the response from the remote device. If the device is sending a valid http response that ohNet doesn't handle, it should be easy to fix this.

(06-07-2012 08:49 AM)dough Wrote:  I understand that I should probably be using async calls to the Upnp device, but I want to keep things simple in the first instance and just have a blocking RPC. One of the reasons that OhNet looks promising is that there is an API ready to make blocking calls and there is no need to implement timeouts and concurrent calling myself.

It should be possible to use the sync action APIs. The only timeout ohNet imposes is on the initial tcp connect to the device's server. This timeout defaults to 3s and can be changed using OhNetInitParamsSetTcpConnectTimeout (note that this needs to be called before OhNetLibraryInitialise).

Any later timeouts would be imposed by either the iOS networking stack or the remote device's http server. These timeouts are likely to be pretty large so shouldn't be affecting you here.

(06-07-2012 08:49 AM)dough Wrote:  BTW: The proxy generated by OhNetGen contained dash characters in both function and variable names which are invalid for names in the C language! I replaced all of the dashes in names with underscores.

Can you PM me the xml for the problem service please? We can update OhNetGen to automatically convert any invalid characters in action or state variable names.
Find all posts by this user
09-07-2012, 04:38 AM (This post was last modified: 09-07-2012 04:40 AM by dough.)
Post: #3
RE: Reason for error on Sync call...
(06-07-2012 09:37 AM)simonc Wrote:  I'm afraid you'll have to add logging to ohNet to get more detailed info. I'd imagine the error is being thrown from InvocationUpnp::Invoke (OpenHome/Net/ControlPoint/Upnp). You could start by adding
Code:
iSocket.LogVerbose(true);
This'll log the request and any response to stderr (or whatever alternative location you setup in OhNetInitParamsSetLogOutput).

I am not exactly sure how I should be adding this...? I cannot find any API call in the C API to LogVerbose globally. I am not so familiar with C++, but I tried adding a the line here and recompiling:

Code:
void InvocationUpnp::Invoke(const Uri& aUri)
{
    LOG(kService, "> InvocationUpnp::Invoke (%p, action ", &iInvocation);
    LOG(kService, iInvocation.Action().Name());
    LOG(kService, ")\n");

    iSocket.LogVerbose(true);
    iSocket.Open();
    WriteRequest(aUri);
    iInvocation.SetInterruptHandler(this);
    ReadResponse();

    LOG(kService, "< InvocationUpnp::Invoke (%p, action ", &iInvocation);
    LOG(kService, iInvocation.Action().Name());
    LOG(kService, ")\n");
}

This didn't seem to give me any additional verbosity on the error message. I wonder if the stderr is being redirected somewhere other than the debug console? Should I expect to see the LOG()s in the above code when DEFINETRACE is defined? In xcode the stderr defaults to the debug console.

I also noticed the LOG() macros and recompiled with DEFINETRACE defined. This gave me the following output when I ran example.

Quote:Socket::Send, sending
POST /ChannelServices/control HTTP/1.0

Host: 192.168.15.234:55335

Content-Length: 297

Content-Type: text/xml; charset="utf-8"

SOAPACTION: "urn:schemas-upnp-org:service:ChannelServices:1#ChannelList_getAsJson"



<?xml version="1.0"?>

<s:Envelope xmlnsConfused="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">

<s:Body>

<u:ChannelList_getAsJson xmlns:u="urn:schemas-upnp-org:service:ChannelServices:1">

</u:ChannelList_getAsJson>

</s:Body>

</s:Envelope>


Socket::Receive, got
HTTP/1.1 200 OK
Socket::Receive, got


EXT:

CONTENT-TYPE: text/xml; charset="utf-8"

SERVER: POSIX, UPnP/1.0, MicroStack/1.0.4384



<?xml version="1.0" encoding="utf-8"?>

<s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlnsConfused="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:ChannelList_getAsJsonResponse xmlns:u="urn:schemas-upnp-org:service:ChannelServices:1"><result>1</result><json_channel_list>[{&quot;handle&quot;: 4026531840, &quot;name&quot;: &quot;CANAL+&quot;, &quot;ID&quot;: &quot;dvb://1.430.2009&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531841, &quot;name&quot;: &quot;CANAL+ SPORT&quot;, &quot;ID&quot;: &quot;dvb://1.430.2024&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531842, &quot;name&quot;: &quot;CANAL+&quot;, &quot;ID&quot;: &quot;dvb://1.430.2013&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531843, &quot;name&quot;: &quot;CANAL+&quot;, &quot;ID&quot;: &quot;dvb://1.430.201d&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531844, &quot;name&quot;: &quot;CANAL+ FAMILY&quot;, &quot;ID&quot;: &quot;dvb://1.430.200d&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531845, &quot;name&quot;: &quot;INFOSPORT+&quot;, &quot;ID&quot;: &quot;dvb://1.430.2011&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531846, &quot;name&quot;: &quot;CANAL+ SPORT&quot;, &quot;ID&quot;: &quot;dvb://1.430.2010&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531847, &quot;name&quot;: &quot;DISNEY CHANNEL&quot;, &quot;ID&quot;: &quot;dvb://1.430.200f&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531848, &quot;name&quot;: &quot;CINE+ PREMIER&quot;, &quot;ID&quot;: &quot;dvb://1.430.200e&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531849, &quot;name&quot;: &quot;CANAL+&quot;, &quot;ID&quot;: &quot;dvb://1.430.200c&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531850, &quot;name&quot;: &quot;CANAL+ CINEMA&quot;, &quot;ID&quot;: &quot;dvb://1.430.200b&quot;, &quot;type&quot;: 1}, {&quot;handle&quot;: 4026531851, &quot;name&quot;: &quot;CANAL+ DECALE&quot;, &quot;ID&quot;: &quot;dvb://1.430.200a&quot;, &quot;type&quot;: 1}]</json_channel_list></u:ChannelList_getAsJsonResponse></s:Body></s:Envelope>
------------------------------
SequenceNumber: 1
Service: urn:schemas-upnp-org:service:ChannelServices:1
Action: ChannelList_getAsJson
ErrorLevel: HTTP
ErrorCode: 1
ErrorDescription: Unknown
------------------------------

Does this indicate an obvious reason for error? (Note: the smilies should be actually ":s" )

I looks to me like the HTTP response is successfully received, but perhaps the payload invalid in some way. Actually, the text in the response is encoded as ASCII by the UPnP Device with unicode characters escaped, but I don't see that this should make the response invalid because ASCII should fit into the UTF-8 character set.?


(06-07-2012 09:37 AM)simonc Wrote:  I'd guess this'll show that the exception comes from InvocationUpnp::ReadResponse being unhappy with something about the response from the remote device. If the device is sending a valid http response that ohNet doesn't handle, it should be easy to fix this.

Clearly, the error is occurring at the HTTP level, but I still don't have enough detail to go on. Can you advise any further tracing, logging debugging methods that might help? (Apologies, but you may have to pinpoint the exact place for me to add code or edit something and what to recompile too!)

Thank you!

Doug
Find all posts by this user
09-07-2012, 08:54 AM
Post: #4
RE: Reason for error on Sync call...
Thanks Doug. This is exactly the info I was looking for. (You're correct that DEFINE_TRACE needs to be defined for any logging to be generated. Apologies for forgetting to mention this.)

The server you're talking to is a bit unusual - it sends responses without either a CONTENT-LENGTH or TRANSFER_ENCODING: chunked header. I hadn't realised this was valid behaviour for a HTTP 1.1 server. I'll update ohNet to handle this sort of response.

Can you let me know which device you're using please? It might be useful for me to buy something similar to help with future testing.
Find all posts by this user
09-07-2012, 09:15 AM
Post: #5
RE: Reason for error on Sync call...
Hi Simon,

Glad that's clarified a few things for you. Actually, my device is a Set-Top Box with a custom UPnP service (which I hope to migrate towards more standard services). The STB is using the UPnP MicroStack which was initially developed by Intel, but now released as open source and community supported (although the support is no where near as responsive as OhNet! Wink ).

Did you manage to verify (against a credible source) that this is indeed correct behaviour for a HTTP 1.1 server then?
What about my use of LogVerbose?
Are you saying that OhNet is rejecting the SOAP response because there is no CONTENT-LENGTH or TRANSFER_ENCODING? Could this be an omission on my Device?

Sincerely,
Doug
Find all posts by this user
09-07-2012, 09:48 AM (This post was last modified: 09-07-2012 11:47 AM by simonc.)
Post: #6
RE: Reason for error on Sync call...
(09-07-2012 09:15 AM)dough Wrote:  Did you manage to verify (against a credible source) that this is indeed correct behaviour for a HTTP 1.1 server then?
What about my use of LogVerbose?
Are you saying that OhNet is rejecting the SOAP response because there is no CONTENT-LENGTH or TRANSFER_ENCODING? Could this be an omission on my Device?

Hi Doug

Your use of LogVerbose was spot on. It has provided the info I was looking for so it is safe for you to remove it now.

Yes, the problem is caused by your server not containing one of the CONTENT-LENGTH or TRANSFER_ENCODING headers in its response. I hadn't realised this was valid for HTTP/1.1 but the RFC (http://www.w3.org/Protocols/rfc2616/rfc2...tml#sec4.4 being most relevant) appears to allow it.

I'll change ohNet to cope with this. It'll probably be tomorrow evening before the code appears on github; I'll post a reply here when the changes are ready.

Simon
Find all posts by this user
09-07-2012, 11:47 AM
Post: #7
RE: Reason for error on Sync call...
(09-07-2012 09:15 AM)dough Wrote:  Glad that's clarified a few things for you. Actually, my device is a Set-Top Box with a custom UPnP service (which I hope to migrate towards more standard services). The STB is using the UPnP MicroStack which was initially developed by Intel, but now released as open source and community supported (although the support is no where near as responsive as OhNet! Wink ).

In case you didn't know, ohNet includes a device stack as well as the control point stack you're already using. If you don't have a lot of existing code using the Intel stack, you might find it easiest to use ohNet on your STB too. This would mean you'd only need to learn one set of APIs etc.

Simon
Find all posts by this user
10-07-2012, 09:21 AM
Post: #8
RE: Reason for error on Sync call...
(09-07-2012 09:48 AM)simonc Wrote:  Yes, the problem is caused by your server not containing one of the CONTENT-LENGTH or TRANSFER_ENCODING headers in its response. I hadn't realised this was valid for HTTP/1.1 but the RFC (http://www.w3.org/Protocols/rfc2616/rfc2...tml#sec4.4 being most relevant) appears to allow it.

I'll change ohNet to cope with this.

I've got a local change that should cope with servers which don't provide a length for response bodies. I won't be able to commit this today so I've included the diffs in case this is blocking you and you want to try applying the changes locally.
Code:
--- a/OpenHome/Net/ControlPoint/Upnp/ProtocolUpnp.cpp
+++ b/OpenHome/Net/ControlPoint/Upnp/ProtocolUpnp.cpp
@@ -104,14 +104,28 @@ void InvocationUpnp::ReadResponse()
     }
     else {
         TUint length = headerContentLength.ContentLength();
-        if (length == 0) {
-            THROW(HttpError);
+        if (length != 0) {
+            Bwh buf(length);
+            while (length > 0) {
+                TUint readBytes = (length<kMaxReadBytes? length : kMaxReadBytes
+                buf.Append(iReadBuffer.Read(readBytes));
+                length -= readBytes;
+            }
+            buf.TransferTo(entity);
         }
-        entity.Grow(length);
-        while (length > 0) {
-            TUint readBytes = (length<kMaxReadBytes? length : kMaxReadBytes);
-            entity.Append(iReadBuffer.Read(readBytes));
-            length -= readBytes;
+        else { // no content length - read until connection closed by server
+            try {
+                for (;;) {
+                    Brn buf = iReadBuffer.Read(kMaxReadBytes);
+                    entity.Grow(entity.Bytes() + kMaxReadBytes);
+                    entity.Append(buf);
+                }
+            }
+            catch (ReaderError&) {
+                Brn snaffle = iReadBuffer.Snaffle();
+                entity.Grow(entity.Bytes() + snaffle.Bytes());
+                entity.Append(snaffle);
+            }
         }
     }
Let me know how you get on if you do give this a try.
Find all posts by this user
11-07-2012, 04:59 AM
Post: #9
RE: Reason for error on Sync call...
Hi Simon,

Great! I am now able to get the responses from actions! Smile

Although I should point out that there is a bit missing from your patch...
Code:
--- a/OpenHome/Net/ControlPoint/Upnp/ProtocolUpnp.cpp
+++ b/OpenHome/Net/ControlPoint/Upnp/ProtocolUpnp.cpp
@@ -104,14 +104,28 @@ void InvocationUpnp::ReadResponse()
     }
     else {
         TUint length = headerContentLength.ContentLength();
-        if (length == 0) {
-            THROW(HttpError);
+        if (length != 0) {
+            Bwh buf(length);
+            while (length > 0) {
+                TUint readBytes = (length<kMaxReadBytes? length : kMaxReadBytes);
+                buf.Append(iReadBuffer.Read(readBytes));
+                length -= readBytes;
+            }
+            buf.TransferTo(entity);
         }
-        entity.Grow(length);
-        while (length > 0) {
-            TUint readBytes = (length<kMaxReadBytes? length : kMaxReadBytes);
-            entity.Append(iReadBuffer.Read(readBytes));
-            length -= readBytes;
+        else { // no content length - read until connection closed by server
+            try {
+                for (;;) {
+                    Brn buf = iReadBuffer.Read(kMaxReadBytes);
+                    entity.Grow(entity.Bytes() + kMaxReadBytes);
+                    entity.Append(buf);
+                }
+            }
+            catch (ReaderError&) {
+                Brn snaffle = iReadBuffer.Snaffle();
+                entity.Grow(entity.Bytes() + snaffle.Bytes());
+                entity.Append(snaffle);
+            }
         }
     }

That should work for others.
Find all posts by this user
11-07-2012, 08:37 AM
Post: #10
RE: Reason for error on Sync call...
Thanks Doug. The fix is now available on github.
Find all posts by this user


Forum Jump: