Errors parsing events

[poirier]

I'm starting to experiment with watching for events, using the example code from the first comment here: #194

But it seems that the event parsing code is failing on some of the events it is receiving. I'm running the SoCo code from master today (9dc84e3).

I added a bit more logging and here's an excerpt.

Event 0 received for sid: uuid:RINCON_B8E937BAA5EA01400_sub0000000164
Current thread is <Thread(Thread-5, started 140382056736512)>
Full event body is:
b'<e:propertyset xmlns:e="urn:schemas-upnp-org:event-1-0"><e:property><LastChange>&lt;Event xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/AVT/&quot; xmlns:r=&quot;urn:schemas-rinconnetworks-com:metadata-1-0/&quot;&gt;&lt;InstanceID val=&quot;0&quot;&gt;&lt;TransportState val=&quot;PLAYING&quot;/&gt;&lt;CurrentPlayMode val=&quot;NORMAL&quot;/&gt;&lt;CurrentCrossfadeMode val=&quot;0&quot;/&gt;&lt;NumberOfTracks val=&quot;11&quot;/&gt;&lt;CurrentTrack val=&quot;1&quot;/&gt;&lt;CurrentSection val=&quot;0&quot;/&gt;&lt;CurrentTrackURI val=&quot;x-file-cifs://syn/music/podcasts/SGU%20%23485.mp3&quot;/&gt;&lt;CurrentTrackDuration val=&quot;1:25:16&quot;/&gt;&lt;CurrentTrackMetaData val=&quot;&amp;lt;DIDL-Lite xmlns:dc=&amp;quot;http://purl.org/dc/elements/1.1/&amp;quot; xmlns:upnp=&amp;quot;urn:schemas-upnp-org:metadata-1-0/upnp/&amp;quot; xmlns:r=&amp;quot;urn:schemas-rinconnetworks-com:metadata-1-0/&amp;quot; xmlns=&amp;quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&amp;quot;&amp;gt;&amp;lt;item id=&amp;quot;-1&amp;quot; parentID=&amp;quot;-1&amp;quot; restricted=&amp;quot;true&amp;quot;&amp;gt;&amp;lt;res protocolInfo=&amp;quot;x-file-cifs:*:audio/mpeg:*&amp;quot; duration=&amp;quot;1:25:16&amp;quot;&amp;gt;x-file-cifs://syn/music/podcasts/SGU%20%23485.mp3&amp;lt;/res&amp;gt;&amp;lt;r:streamContent&amp;gt;&amp;lt;/r:streamContent&amp;gt;&amp;lt;r:radioShowMd&amp;gt;&amp;lt;/r:radioShowMd&amp;gt;&amp;lt;upnp:albumArtURI&amp;gt;/getaa?u=x-file-cifs%3a%2f%2fsyn%2fmusic%2fpodcasts%2fSGU%2520%2523485.mp3&amp;amp;amp;v=9&amp;lt;/upnp:albumArtURI&amp;gt;&amp;lt;dc:title&amp;gt;Skeptics Guide #485&amp;lt;/dc:title&amp;gt;&amp;lt;upnp:class&amp;gt;object.item.audioItem.musicTrack&amp;lt;/upnp:class&amp;gt;&amp;lt;dc:creator&amp;gt;SGU Productions&amp;lt;/dc:creator&amp;gt;&amp;lt;upnp:album&amp;gt;Skeptics Guide&amp;lt;/upnp:album&amp;gt;&amp;lt;r:albumArtist&amp;gt;SGU Productions&amp;lt;/r:albumArtist&amp;gt;&amp;lt;/item&amp;gt;&amp;lt;/DIDL-Lite&amp;gt;&quot;/&gt;&lt;r:NextTrackURI val=&quot;x-file-cifs://syn/music/podcasts/SGU%20%23486.mp3&quot;/&gt;&lt;r:NextTrackMetaData val=&quot;&amp;lt;DIDL-Lite xmlns:dc=&amp;quot;http://purl.org/dc/elements/1.1/&amp;quot; xmlns:upnp=&amp;quot;urn:schemas-upnp-org:metadata-1-0/upnp/&amp;quot; xmlns:r=&amp;quot;urn:schemas-rinconnetworks-com:metadata-1-0/&amp;quot; xmlns=&amp;quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&amp;quot;&amp;gt;&amp;lt;item id=&amp;quot;-1&amp;quot; parentID=&amp;quot;-1&amp;quot; restricted=&amp;quot;true&amp;quot;&amp;gt;&amp;lt;res protocolInfo=&amp;quot;x-file-cifs:*:audio/mpeg:*&amp;quot; duration=&amp;quot;1:19:19&amp;quot;&amp;gt;x-file-cifs://syn/music/podcasts/SGU%20%23486.mp3&amp;lt;/res&amp;gt;&amp;lt;upnp:albumArtURI&amp;gt;/getaa?u=x-file-cifs%3a%2f%2fsyn%2fmusic%2fpodcasts%2fSGU%2520%2523486.mp3&amp;amp;amp;v=9&amp;lt;/upnp:albumArtURI&amp;gt;&amp;lt;dc:title&amp;gt;Skeptics Guide #486&amp;lt;/dc:title&amp;gt;&amp;lt;upnp:class&amp;gt;object.item.audioItem.musicTrack&amp;lt;/upnp:class&amp;gt;&amp;lt;dc:creator&amp;gt;SGU Productions&amp;lt;/dc:creator&amp;gt;&amp;lt;upnp:album&amp;gt;Skeptics Guide&amp;lt;/upnp:album&amp;gt;&amp;lt;r:albumArtist&amp;gt;SGU Productions&amp;lt;/r:albumArtist&amp;gt;&amp;lt;/item&amp;gt;&amp;lt;/DIDL-Lite&amp;gt;&quot;/&gt;&lt;r:EnqueuedTransportURI val=&quot;x-rincon-playlist:RINCON_B8E937BAA5EA01400#S://syn/music/podcasts&quot;/&gt;&lt;r:EnqueuedTransportURIMetaData val=&quot;&amp;lt;DIDL-Lite xmlns:dc=&amp;quot;http://purl.org/dc/elements/1.1/&amp;quot; xmlns:upnp=&amp;quot;urn:schemas-upnp-org:metadata-1-0/upnp/&amp;quot; xmlns:r=&amp;quot;urn:schemas-rinconnetworks-com:metadata-1-0/&amp;quot; xmlns=&amp;quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&amp;quot;&amp;gt;&amp;lt;item id=&amp;quot;S://syn/music/podcasts&amp;quot; parentID=&amp;quot;S://syn/music&amp;quot; restricted=&amp;quot;true&amp;quot;&amp;gt;&amp;lt;dc:title&amp;gt;podcasts&amp;lt;/dc:title&amp;gt;&amp;lt;upnp:class&amp;gt;object.container&amp;lt;/upnp:class&amp;gt;&amp;lt;desc id=&amp;quot;cdudn&amp;quot; nameSpace=&amp;quot;urn:schemas-rinconnetworks-com:metadata-1-0/&amp;quot;&amp;gt;RINCON_AssociatedZPUDN&amp;lt;/desc&amp;gt;&amp;lt;/item&amp;gt;&amp;lt;/DIDL-Lite&amp;gt;&quot;/&gt;&lt;PlaybackStorageMedium val=&quot;NETWORK&quot;/&gt;&lt;AVTransportURI val=&quot;x-rincon-queue:RINCON_B8E937BAA5EA01400#0&quot;/&gt;&lt;AVTransportURIMetaData val=&quot;&quot;/&gt;&lt;NextAVTransportURI val=&quot;&quot;/&gt;&lt;NextAVTransportURIMetaData val=&quot;&quot;/&gt;&lt;CurrentTransportActions val=&quot;Set, Play, Stop, Pause, Seek, Next, Previous&quot;/&gt;&lt;r:CurrentValidPlayModes val=&quot;SHUFFLE, REPEAT, CROSSFADE&quot;/&gt;&lt;TransportStatus val=&quot;OK&quot;/&gt;&lt;r:SleepTimerGeneration val=&quot;0&quot;/&gt;&lt;r:AlarmRunning val=&quot;0&quot;/&gt;&lt;r:SnoozeRunning val=&quot;0&quot;/&gt;&lt;r:RestartPending val=&quot;0&quot;/&gt;&lt;TransportPlaySpeed val=&quot;NOT_IMPLEMENTED&quot;/&gt;&lt;CurrentMediaDuration val=&quot;NOT_IMPLEMENTED&quot;/&gt;&lt;RecordStorageMedium val=&quot;NOT_IMPLEMENTED&quot;/&gt;&lt;PossiblePlaybackStorageMedia val=&quot;NONE, NETWORK&quot;/&gt;&lt;PossibleRecordStorageMedia val=&quot;NOT_IMPLEMENTED&quot;/&gt;&lt;RecordMediumWriteStatus val=&quot;NOT_IMPLEMENTED&quot;/&gt;&lt;CurrentRecordQualityMode val=&quot;NOT_IMPLEMENTED&quot;/&gt;&lt;PossibleRecordQualityModes val=&quot;NOT_IMPLEMENTED&quot;/&gt;&lt;/InstanceID&gt;&lt;/Event&gt;</LastChange></e:property></e:propertyset>'
Exception parsing value '<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:r="urn:schemas-rinconnetworks-com:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="S://syn/music/podcasts" parentID="S://syn/music" restricted="true"><dc:title>podcasts</dc:title><upnp:class>object.container</upnp:class><desc id="cdudn" nameSpace="urn:schemas-rinconnetworks-com:metadata-1-0/">RINCON_AssociatedZPUDN</desc></item></DIDL-Lite>' with from_didl_string
Traceback (most recent call last):
  File "/home/poirier/VE/soso/lib/python3.4/site-packages/soco/events.py", line 136, in parse_event_xml
    value = from_didl_string(value)[0]
  File "/home/poirier/VE/soso/lib/python3.4/site-packages/soco/data_structures.py", line 79, in from_didl_string
    items.append(cls.from_element(elt))
  File "/home/poirier/VE/soso/lib/python3.4/site-packages/soco/data_structures.py", line 352, in from_element
    " got '<{1}>'".format(cls.tag, element.tag))
soco.exceptions.DIDLMetadataError: Wrong element. Expected '<container>', got '<{urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/}item>'

[lawrenceakka]

Hmmm...

I've been seeing a few of these errors recently. It looks as though the Sonos firmware fails properly to stick to the official UPnP DIDL-Lite specification. For example, a DIDL object.container should be represented in XML by a tag, but Sonos sometimes (but not always) uses an tag instead.

For the moment, the best fix will be to remove the check at line 349 of data_structures.py, i,e, comment out the following lines:

        if not element.tag.endswith(cls.tag):
            raise DIDLMetadataError(
                "Wrong element. Expected '<{0}>',"
                " got '<{1}>'".format(cls.tag, element.tag))

I'll push a fix when I can figure out what's going on

[mikix]

Looks like this workaround was applied and then unapplied? I'm still seeing this issue.

[donhoffman]

Still seeing this also. Version of soco installed is 0.11.1.

[KennethNielsen]

@mikix I'm unsure if it was ever applied. The way I read @lawrenceakka message, he would look more into it before applying it (and then I guess he got busy with real life). The problem with just applying is, that these message in principle should follow a specification and that is helpful to make sure that we understand the content. Applying the fix would remove a large part of the checks of specification adherence which is not really desirable. What would be better is, if we have to deviate from the spec, to do so in as limited and well documented manner as possible.

I'll look into this and at adding some code to hopefully capture event streams to make it easier to share failing events and debug them. I know this sucks, but have a little more patience.

[lawrenceakka]

It appears that Sonos uses <item> tags for things where the UPnP spec requires <container> tags, e.g. object.container.playlistContainer is an item not a container !. I have fixed a few tags, and improved the error messages to help track down this problem in future. Please let me know if there are ongoing problems