search

intel / dleyna-renderer

dleyna-renderer is a library for implementing services that allow clients to discover and manipulate Digital Media Renderers. An implementation of such a service for linux is also included
https://01.org/dleyna/
GNU Lesser General Public License v2.1
16 stars 19 forks source link

We respond "HTTP code 200 - OK" instead of 412 to an event with a blank SID #26

Open cprigent opened 11 years ago

cprigent commented 11 years ago

Setup:

* gssdp 0.14.1: 35cd6c5
* gupnp 0.20.0: 5765f46
* gupnp-av 0.12.0: 71806e4
* gupnp-dlna 0.9.5: fed5da3
* media-service-upnp 0.5: 0dbc74a
* render-service-upnp 0.3.1: 8b6ab83
* cloudeebus: 1ed7b8b
* cloud-dleyna: 00c8ed7

Pre-conditions

Requirement level is: "Should support"

Steps:

1 Launch test 7.2.16.1 DDC UPnP Error Codes: Verification of Proper Error Code Usage 2 Wait result

Actual result:

2 Test result is "Warning"

Expected result:

4 Test result is Pass

cprigent commented 11 years ago

Debug log from the DLNA CTT:

06/03/2013 14:34:46: INFO: *** Starting Test: => "7.2.16.1 DDC UPnP Error Codes: Verification of Proper Error Code Usage."
06/03/2013 14:34:46: INFO:     Description: To verify that a UPnP CP should use and return the proper error code when encountering an error condition in a UPnP operation.
06/03/2013 14:34:46: INFO: Step 1: Checking if the DUT Supports Subscribing to Events.
06/03/2013 14:34:46: INFO: DUT Supports Subscribing to Events.
06/03/2013 14:34:46: INFO: DUT subscribes to events starting simulator.
06/03/2013 14:34:46: INFO: Step 2: Starting the correct simulator based on the DUT device class.
06/03/2013 14:34:47: INFO: Starting a DMR and DMS simulator.
06/03/2013 14:34:47: INFO: Step 3: Waiting for the DUT send a Subscription.
06/03/2013 14:34:48: INFO: Received a subscription request from DUT for service urn:schemas-upnp-org:service:ConnectionManager:1.
06/03/2013 14:34:48: INFO: Received a subscription request from DUT for service urn:schemas-upnp-org:service:AVTransport:1.
06/03/2013 14:34:48: INFO: Received a subscription request from DUT for service urn:schemas-upnp-org:service:RenderingControl:1.
06/03/2013 14:34:49: INFO: Step 3: Sending a set of NOTIFY's for each subscription.
06/03/2013 14:34:49: INFO: Testing subscription: 0
06/03/2013 14:34:49: INFO: Step 3.1: Sending the DUT an event without the SID header.
06/03/2013 14:34:49: INFO: Sending Notify.
06/03/2013 14:34:49: INFO: Client returned an HTTP code of 412 - Precondition Failed
06/03/2013 14:34:49: INFO: Passed, DUT responded with an HTTP reponse of 412
06/03/2013 14:34:49: INFO: Step 3.2: Sending the DUT an event with a blank SID.
06/03/2013 14:34:49: INFO: Sending Notify.
06/03/2013 14:34:49: INFO: Received a subscription request from DUT for service urn:schemas-upnp-org:service:ContentDirectory:1.
06/03/2013 14:34:49: INFO: Client returned an HTTP code of 200 - OK
06/03/2013 14:34:49: ERROR: DUT did not respond an error code of 412, DUT HTTP response = 200
06/03/2013 14:34:49: INFO: Stopping the Simulator
06/03/2013 14:34:49: INFO: Received a subscription request from DUT for service urn:schemas-upnp-org:service:ConnectionManager:1.
06/03/2013 14:34:54: INFO: Received a subscription request from DUT for service urn:schemas-upnp-org:service:ConnectionManager:1.
06/03/2013 14:35:04: WARNING: 7.2.16.1 DDC UPnP Error Codes: Verification of Proper Error Code Usage. (Version: 1.5.58.2): DUT did not return the correct UPnP error code(s).
jku commented 11 years ago

I'll fix this, it's trivial.

That said, I probably need to get access to a test system... otherwise sooner or later I'll end up 'fixing' something that doesn't actually make the error go away. As an example, is it 100% certain that "blank" referes to an empty string or are there other ways a string can be "blank" (say, a string of whitespace).

cprigent commented 11 years ago

Here is Log from dleyna-renderer-service:

GET /device.xml HTTP/1.1
> Soup-Debug-Timestamp: 1363801135
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 10 (0xedab10), SoupSocket 10 (0xea1210)
> Host: 192.168.1.7:25243
> Accept-Encoding: gzip, deflate
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1363801135
< Soup-Debug: SoupMessage 10 (0xedab10)
< Content-Type: text/xml; charset="utf-8"
< Content-Length: 1583
< 
< <?xml version="1.0" encoding="utf-8" ?>
< <root xmlns="urn:schemas-upnp-org:device-1-0" xmlns:dlna="urn:schemas-dlna-org:device-1-0">
<   <specVersion>
<     <major>1</major>
<     <minor>0</minor>
<   </specVersion>
<      <device>
<        <dlna:X_DLNADOC>DMS-1.50</dlna:X_DLNADOC>
<        <deviceType>urn:schemas-upnp-org:device:MediaServer:1</deviceType>
<        <friendlyName>7.2.16.1 DMS</friendlyName>
<        <manufacturer>DLNA</manufacturer>
<        <modelName>ACME SPECIAL</modelName>
<        <UDN>uuid:cce28f07-a79a-4aa5-857b-5fcc4f7f4d04</UDN>
<     <serviceList>
<       <service>
<         <serviceType>urn:schemas-upnp-org:service:ContentDirectory:1</serviceType>
<         <serviceId>urn:upnp-org:serviceId:ContentDirectory</serviceId>
<         <controlURL>/cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Control/</controlURL>
<         <eventSubURL>/cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Subscribe/</eventSubURL>
<         <SCPDURL>/cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_SCPD.xml</SCPDURL>
<       </service>
<       <service>
<         <serviceType>urn:schemas-upnp-org:service:ConnectionManager:1</serviceType>
<         <serviceId>urn:upnp-org:serviceId:ConnectionManager</serviceId>
<         <controlURL>/cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ConnectionManager_Control/</controlURL>
<         <eventSubURL>/cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ConnectionManager_Subscribe/</eventSubURL>
<         <SCPDURL>/cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ConnectionManager_SCPD.xml</SCPDURL>
<       </service>
<     </serviceList>
<      </device>
< </root>

dleyna-server-service[1624]: upnp.c : prv_server_available_cb() --- UDN uuid:cce28f07-a79a-4aa5-857b-5fcc4f7f4d04
dleyna-server-service[1624]: upnp.c : prv_server_available_cb() --- IP Address 192.168.1.2
dleyna-server-service[1624]: upnp.c : prv_server_available_cb() --- Device not found. Adding
dleyna-server-service[1624]:  
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_processor_add_queue() --- Enter - queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_processor_add_queue() --- Exit
dleyna-server-service[1624]: device.c : dls_device_new() --- New Device on 192.168.1.2
dleyna-server-service[1624]: device.c : dls_device_new() --- Server Path /com/intel/dLeynaServer/server/1
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_start() --- Enter - Starting queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_start() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
> POST /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Control/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801135
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 11 (0xedaa30), SoupSocket 11 (0xea1420)
> Host: 192.168.1.7:25243
> SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSearchCapabilities"
> Accept-Encoding: gzip
> Content-Type: text/xml; charset="utf-8"
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive
> 
> <?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetSearchCapabilities xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"></u:GetSearchCapabilities></s:Body></s:Envelope>

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1363801135
< Soup-Debug: SoupMessage 11 (0xedaa30)
< Content-Type: text/xml; charset="utf-8"
< Server: Microsoft Windows 7 Home Premium /6.1.7601 UPnP/1.0 7.2.16.1 DMS/1.0
< Date: Wed, 20 Mar 2013 17:38:52 GMT
< Ext: 
< Content-Length: 304
< 
< <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetSearchCapabilitiesResponse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"><SearchCaps></SearchCaps></u:GetSearchCapabilitiesResponse></s:Body></s:Envelope>

dleyna-server-service[1624]: device.c : prv_get_search_capabilities_cb() --- GetSearchCapabilities result: 
dleyna-server-service[1624]: device.c : prv_get_capabilities_analyze() ---    Variant = []
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
> POST /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Control/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801135
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 12 (0xeda950), SoupSocket 12 (0xea14d0)
> Host: 192.168.1.7:25243
> SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSortCapabilities"
> Accept-Encoding: gzip
> Content-Type: text/xml; charset="utf-8"
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive
> 
> <?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetSortCapabilities xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"></u:GetSortCapabilities></s:Body></s:Envelope>

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1363801135
< Soup-Debug: SoupMessage 12 (0xeda950)
< Content-Type: text/xml; charset="utf-8"
< Server: Microsoft Windows 7 Home Premium /6.1.7601 UPnP/1.0 7.2.16.1 DMS/1.0
< Date: Wed, 20 Mar 2013 17:38:52 GMT
< Ext: 
< Content-Length: 304
< 
< <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetSortCapabilitiesResponse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"><SortCaps>dc:title</SortCaps></u:GetSortCapabilitiesResponse></s:Body></s:Envelope>

dleyna-server-service[1624]: device.c : prv_get_sort_capabilities_cb() --- GetSortCapabilities result: dc:title
dleyna-server-service[1624]: device.c : prv_get_capabilities_analyze() ---    Variant = ['DisplayName']
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
> POST /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Control/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801135
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 13 (0xeda870), SoupSocket 13 (0xea1370)
> Host: 192.168.1.7:25243
> SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSortExtensionCapabilities"
> Accept-Encoding: gzip
> Content-Type: text/xml; charset="utf-8"
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive
> 
> <?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetSortExtensionCapabilities xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"></u:GetSortExtensionCapabilities></s:Body></s:Envelope>

< HTTP/1.1 500 Internal Server Error
< Soup-Debug-Timestamp: 1363801136
< Soup-Debug: SoupMessage 13 (0xeda870)
< Content-Type: text/xml; charset="utf-8"
< Server: UPnP/1.0 DMS Simulator 1.0
< Date: Wed, 20 Mar 2013 17:38:52 GMT
< Ext: 
< Content-Length: 398
< 
< <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><s:Fault><faultcode>s:Client</faultcode><faultstring>UPnPError</faultstring><detail><UPnPError xmlns="urn:schemas-upnp-org:control-1-0"><errorCode>401</errorCode><errorDescription>Invalid Action</errorDescription></UPnPError></detail></s:Fault></s:Body></s:Envelope>

dleyna-server-service[1624]: device.c : prv_get_sort_ext_capabilities_cb() --- GetSortExtensionCapabilities operation failed: Invalid Action
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
> POST /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Control/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801136
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 14 (0xeda870), SoupSocket 14 (0xea14d0)
> Host: 192.168.1.7:25243
> SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#GetFeatureList"
> Accept-Encoding: gzip
> Content-Type: text/xml; charset="utf-8"
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive
> 
> <?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetFeatureList xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"></u:GetFeatureList></s:Body></s:Envelope>

< HTTP/1.1 500 Internal Server Error
< Soup-Debug-Timestamp: 1363801136
< Soup-Debug: SoupMessage 14 (0xeda870)
< Content-Type: text/xml; charset="utf-8"
< Server: UPnP/1.0 DMS Simulator 1.0
< Date: Wed, 20 Mar 2013 17:38:52 GMT
< Ext: 
< Content-Length: 398
< 
< <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><s:Fault><faultcode>s:Client</faultcode><faultstring>UPnPError</faultstring><detail><UPnPError xmlns="urn:schemas-upnp-org:control-1-0"><errorCode>401</errorCode><errorDescription>Invalid Action</errorDescription></UPnPError></detail></s:Fault></s:Body></s:Envelope>

dleyna-server-service[1624]: device.c : prv_get_feature_list_cb() --- GetFeatureList operation failed: Invalid Action
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <source-2,dleyna-server>
dleyna-server-service[1624]: device.c : dls_device_subscribe_to_contents_change() --- Subscribe for events on context: 192.168.1.2
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <source-2,dleyna-server>
dleyna-server-service[1624]: src/connector-dbus.c : prv_connector_publish_subtree() --- Enter, path = </com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: src/connector-dbus.c : prv_connector_publish_subtree() --- Exit, object_id = 2
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Removing queue <source-2,dleyna-server>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_free_cb() --- Enter
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_free_cb() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
dleyna-server-service[1624]: upnp.c : prv_device_chain_end() --- Enter
dleyna-server-service[1624]: upnp.c : prv_device_chain_end() --- Notify new server available: /com/intel/dLeynaServer/server/1
dleyna-server-service[1624]:  
> SUBSCRIBE /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Subscribe/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801136
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 15 (0xeda950), SoupSocket 15 (0xea1370)
> Host: 192.168.1.7:25243
> Callback: <http://192.168.1.2:59997/ServiceProxy1>
> NT: upnp:event
> Timeout: Second-1800
> Accept-Encoding: gzip, deflate
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive

dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_processor_add_queue() --- Enter - queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_processor_add_queue() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: server.c : prv_process_async_task() --- Enter
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Enter
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Path: /com/intel/dLeynaServer/server/1
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Interface (null)
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Root Object = 1
dleyna-server-service[1624]: device.c : dls_device_get_all_props() --- Enter
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop Location = http://192.168.1.7:25243/device.xml
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop UDN = uuid:cce28f07-a79a-4aa5-857b-5fcc4f7f4d04
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop DeviceType = urn:schemas-upnp-org:device:MediaServer:1
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop FriendlyName = 7.2.16.1 DMS
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop Manufacturer = DLNA
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop ModelName = ACME SPECIAL
dleyna-server-service[1624]: device.c : prv_get_system_update_id_for_props() --- Enter
dleyna-server-service[1624]: device.c : prv_get_sr_token_for_props() --- Enter
dleyna-server-service[1624]: device.c : prv_get_sr_token_for_props() --- Exit
dleyna-server-service[1624]: device.c : prv_get_system_update_id_for_props() --- Exit
dleyna-server-service[1624]: device.c : dls_device_get_all_props() --- Exit
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Exit with SUCCESS
dleyna-server-service[1624]: server.c : prv_process_async_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
dleyna-server-service[1624]: async.c : dls_async_task_complete() --- Enter. Error (nil)
dleyna-server-service[1624]:  
dleyna-server-service[1624]: server.c : prv_async_task_complete() --- Enter
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: server.c : prv_async_task_complete() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: server.c : prv_process_async_task() --- Enter
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Enter
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Path: /com/intel/dLeynaServer/server/1
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Interface (null)
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Root Object = 1
dleyna-server-service[1624]: device.c : dls_device_get_all_props() --- Enter
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props() --- Enter called
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props() --- Exit with SUCCESS
dleyna-server-service[1624]: device.c : dls_device_get_all_props() --- Exit
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Exit with SUCCESS
dleyna-server-service[1624]: server.c : prv_process_async_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
> POST /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Control/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801136
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 16 (0xedaa30), SoupSocket 16 (0xea12c0)
> Host: 192.168.1.7:25243
> SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
> Accept-Encoding: gzip
> Content-Type: text/xml; charset="utf-8"
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive
> 
> <?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:Browse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"><RequestedCount>0</RequestedCount><StartingIndex>0</StartingIndex><ObjectID>0</ObjectID><BrowseFlag>BrowseMetadata</BrowseFlag><Filter>*</Filter><SortCriteria></SortCriteria></u:Browse></s:Body></s:Envelope>

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1363801136
< Soup-Debug: SoupMessage 15 (0xeda950)
< Timeout: Second-1800
< Date: Wed, 20 Mar 2013 17:38:52 GMT
< Server: Microsoft Windows 7 Home Premium /6.1.7601 UPnP/1.0 7.2.16.1 DMS/1.0
< SID: uuid:982a96b8-a6fc-4780-a3db-c36587556ba0
< Content-Length: 0
< 

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1363801136
< Soup-Debug: SoupMessage 16 (0xedaa30)
< Content-Type: text/xml; charset="utf-8"
< Server: Microsoft Windows 7 Home Premium /6.1.7601 UPnP/1.0 7.2.16.1 DMS/1.0
< Date: Wed, 20 Mar 2013 17:38:53 GMT
< Ext: 
< Content-Length: 1006
< 
< <?xml version="1.0" encoding="utf-8"?>
< <s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
<    <s:Body>
< <u:BrowseResponse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1">
< <Result>&lt;DIDL-Lite xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot; xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns:dlna=&quot;urn:schemas-dlna-org:metadata-1-0/&quot;&gt;
<   &lt;container id=&quot;0&quot; parentID=&quot;-1&quot; restricted=&quot;1&quot;  childCount=&quot;5&quot;&gt;
<     &lt;dc:title&gt;ROOT&lt;/dc:title&gt;
<     &lt;upnp:class&gt;object.container&lt;/upnp:class&gt;
<     &lt;dc:date&gt;2013-03-20&lt;/dc:date&gt;
<   &lt;/container&gt;&lt;/DIDL-Lite&gt;</Result>         <NumberReturned>1</NumberReturned>
<          <TotalMatches>1</TotalMatches>
<          <UpdateID>1</UpdateID>
<       </u:BrowseResponse>
<    </s:Body>
< </s:Envelope>

dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props_cb() --- Enter
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props_cb() --- GetMS2SpecProps result: <DIDL-Lite xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/">
  <container id="0" parentID="-1" restricted="1"  childCount="5">
    <dc:title>ROOT</dc:title>
    <upnp:class>object.container</upnp:class>
    <dc:date>2013-03-20</dc:date>
  </container></DIDL-Lite>
dleyna-server-service[1624]: props.c : prv_add_uint_prop() --- Prop ChildCount = 5
dleyna-server-service[1624]: props.c : prv_add_bool_prop() --- Prop Searchable = 0
dleyna-server-service[1624]: props.c : prv_add_uint_prop() --- Prop ContainerUpdateID = 0
dleyna-server-service[1624]: props.c : prv_add_uint_prop() --- Prop TotalDeletedChildCount = 0
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props_cb() --- Exit
dleyna-server-service[1624]: async.c : dls_async_task_complete() --- Enter. Error (nil)
dleyna-server-service[1624]:  
dleyna-server-service[1624]: server.c : prv_async_task_complete() --- Enter
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: server.c : prv_async_task_complete() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Enter - Task added to queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_add_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Enter - Start task processing for queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: server.c : prv_process_async_task() --- Enter
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Enter
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Path: /com/intel/dLeynaServer/server/1
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Interface (null)
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Root Object = 1
dleyna-server-service[1624]: device.c : dls_device_get_all_props() --- Enter
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props() --- Enter called
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props() --- Exit with SUCCESS
dleyna-server-service[1624]: device.c : dls_device_get_all_props() --- Exit
dleyna-server-service[1624]: upnp.c : dls_upnp_get_all_props() --- Exit with SUCCESS
dleyna-server-service[1624]: server.c : prv_process_async_task() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_process_task() --- Exit
> POST /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Control/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801136
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 17 (0xedab10), SoupSocket 17 (0xea1000)
> Host: 192.168.1.7:25243
> SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
> Accept-Encoding: gzip
> Content-Type: text/xml; charset="utf-8"
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive
> 
> <?xml version="1.0"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:Browse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1"><RequestedCount>0</RequestedCount><StartingIndex>0</StartingIndex><ObjectID>0</ObjectID><BrowseFlag>BrowseMetadata</BrowseFlag><Filter>*</Filter><SortCriteria></SortCriteria></u:Browse></s:Body></s:Envelope>

< HTTP/1.1 200 OK
< Soup-Debug-Timestamp: 1363801136
< Soup-Debug: SoupMessage 17 (0xedab10)
< Content-Type: text/xml; charset="utf-8"
< Server: Microsoft Windows 7 Home Premium /6.1.7601 UPnP/1.0 7.2.16.1 DMS/1.0
< Date: Wed, 20 Mar 2013 17:38:53 GMT
< Ext: 
< Content-Length: 1006
< 
< <?xml version="1.0" encoding="utf-8"?>
< <s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
<    <s:Body>
< <u:BrowseResponse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1">
< <Result>&lt;DIDL-Lite xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot; xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot; xmlns:dlna=&quot;urn:schemas-dlna-org:metadata-1-0/&quot;&gt;
<   &lt;container id=&quot;0&quot; parentID=&quot;-1&quot; restricted=&quot;1&quot;  childCount=&quot;5&quot;&gt;
<     &lt;dc:title&gt;ROOT&lt;/dc:title&gt;
<     &lt;upnp:class&gt;object.container&lt;/upnp:class&gt;
<     &lt;dc:date&gt;2013-03-20&lt;/dc:date&gt;
<   &lt;/container&gt;&lt;/DIDL-Lite&gt;</Result>         <NumberReturned>1</NumberReturned>
<          <TotalMatches>1</TotalMatches>
<          <UpdateID>1</UpdateID>
<       </u:BrowseResponse>
<    </s:Body>
< </s:Envelope>

dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props_cb() --- Enter
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props_cb() --- GetMS2SpecProps result: <DIDL-Lite xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/">
  <container id="0" parentID="-1" restricted="1"  childCount="5">
    <dc:title>ROOT</dc:title>
    <upnp:class>object.container</upnp:class>
    <dc:date>2013-03-20</dc:date>
  </container></DIDL-Lite>
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop DisplayName = ROOT
dleyna-server-service[1624]: props.c : prv_add_path_prop() --- Prop Path = /com/intel/dLeynaServer/server/1
dleyna-server-service[1624]: props.c : prv_add_path_prop() --- Prop Parent = /com/intel/dLeynaServer/server/1
dleyna-server-service[1624]: props.c : prv_add_string_prop() --- Prop Type = container
dleyna-server-service[1624]: props.c : prv_add_bool_prop() --- Prop Restricted = 1
dleyna-server-service[1624]: props.c : prv_add_uint_prop() --- Prop ObjectUpdateID = 0
dleyna-server-service[1624]: device.c : prv_get_all_ms2spec_props_cb() --- Exit
dleyna-server-service[1624]: async.c : dls_async_task_complete() --- Enter. Error (nil)
dleyna-server-service[1624]:  
dleyna-server-service[1624]: server.c : prv_async_task_complete() --- Enter
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Enter - Task completed for queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_queue_task_completed() --- Exit
dleyna-server-service[1624]: server.c : prv_async_task_complete() --- Exit
dleyna-server-service[1624]: device.c : prv_system_update_cb() --- System Update 1
dleyna-server-service[1624]:  
dleyna-server-service[1624]:  
dleyna-server-service[1624]: upnp.c : prv_server_unavailable_cb() --- Enter
dleyna-server-service[1624]: upnp.c : prv_server_unavailable_cb() --- UDN uuid:cce28f07-a79a-4aa5-857b-5fcc4f7f4d04
dleyna-server-service[1624]: upnp.c : prv_server_unavailable_cb() --- IP Address 192.168.1.2
dleyna-server-service[1624]: upnp.c : prv_server_unavailable_cb() --- Last Context lost. Delete device
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_processor_remove_queues_for_sink() --- Enter - Sink </com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_free_queue_for_sink() --- Removing queue <:1.198,/com/intel/dLeynaServer/server/1>
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_free_cb() --- Enter
dleyna-server-service[1624]: libdleyna/core/task-processor.c : prv_free_cb() --- Exit
dleyna-server-service[1624]: libdleyna/core/task-processor.c : dleyna_task_processor_remove_queues_for_sink() --- Exit
dleyna-server-service[1624]: src/connector-dbus.c : prv_connector_unpublish_subtree() --- Enter, object_id = 2
dleyna-server-service[1624]: src/connector-dbus.c : prv_connector_unpublish_subtree() --- Exit
dleyna-server-service[1624]: upnp.c : prv_server_unavailable_cb() --- Exit
dleyna-server-service[1624]:  
> UNSUBSCRIBE /cce28f07-a79a-4aa5-857b-5fcc4f7f4d04/ContentDirectory_Subscribe/ HTTP/1.1
> Soup-Debug-Timestamp: 1363801146
> Soup-Debug: SoupSessionAsync 1 (0xed1120), SoupMessage 18 (0xedacd0), SoupSocket 18 (0xea1420)
> Host: 192.168.1.7:25243
> SID: uuid:982a96b8-a6fc-4780-a3db-c36587556ba0
> Accept-Encoding: gzip, deflate
> User-Agent: dLeyna/0.0.1 GUPnP/0.20.1 DLNADOC/1.50
> Connection: Keep-Alive

< HTTP/1.1 401 Resource not found.
< Soup-Debug-Timestamp: 1363801146
< Soup-Debug: SoupMessage 18 (0xedacd0)
<
jku commented 11 years ago

Thanks for the wireshark log email: there was indeed a plot twist: "empty SID" actually means string "uuid:" and not an empty string.

jku commented 11 years ago

https://bugzilla.gnome.org/show_bug.cgi?id=696289

cguiraud commented 11 years ago

Hi Jussy, I've checked your gupnp patch with the test tool, it fixes partially the test case as it allows the test tool to go further with the HTTP error codes testing. Please find below the headers sent by the test tool and the HTTP error codes expected to have the TC successful.

SID HDR = (null) -> HTTP 412

SID HDR = uuid: -> HTTP 412

SID HDR = uuid:BADsid -> HTTP 412

NT HDR = (null) -> HTTP 400

NT HDR = upnp:BADevent -> HTTP 412

NTS HDR = (null) -> HTTP 400

NTS HDR = upnp:BADpropchange -> HTTP 412