Announcement

Collapse
No announcement yet.

Sonos4 v4.0.1.12, new log errors

Collapse
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

    Sonos4 v4.0.1.12, new log errors

    - Running Sonos4 v4.0.1.12 on Win 10 Pro, HS4 4.2.7.0 as a service

    Hi Dirk, just an FYI: updated Sonos4 from 4.0.1.11 to 4.0.1.12 earlier this week and while the plugin and Sonos players appear to be working properly, I'm now finding errors in the log that I did not see prior to the update. Below is a summary of the errors and I've attached a (zipped) debug log.
    • GetPicture called with url= https://cont-1.p-cdn.us/undefined_500W_500H.jpg caused error: The remote server returned an error: (403) Forbidden.
    • ERROR in SetTransportState for zoneplayer = Master Bedroom with UPNP Error = Read only tag / Transport is locked / Access denied. Error = MyUPnPService.InvokeAction for ServiceID = http://xxx.xxx.xxx.xxx:1400/xml/AVTransport1.xml while sending Action = Pause for URI = http://xxx.xxx.xxx.xxx:1400/MediaRenderer/AVTransport/Control and Request = 0 UPNP Error = faultcode = s:Client, faultstring = UPnPError, detail = 701 with error = The remote server returned an error: (500) Internal Server Error.
    • UpdateRadioStationsInfo unable write this record for zoneplayer = Master Bedroom with error - database is locked database is locked
    Again, not a big deal, just thought you'd like to know.

    Best regards,
    -Mark-
    Attached Files
    Best regards,
    -Mark-

    If you're not out on the edge, you're taking up too much room!
    Interested in 3D maps? Check out my company site: Solid Terrain Modeling

    #2
    The get picture error is caused because the player tells the PI where the art can be retrieved, but as you can see it is a CDN site that probably timed out the content.
    Second error, this happened due to a pause ALL command that is sent to a player that is most likely idle and therefore doesn't like to be told what to do.
    The last one is of more concern. Do you see more of those. It could indicate your radiostation DB is corrupt or opened by something else or you have no access rights (ex not running as admin).

    Comment


      #3
      I'm seeing a uPNP error in my logs as well. I'm running the PI version 4.0.1.12 also. The error is repeatable.


      Click image for larger version

Name:	Screenshot 2022-03-07 071343.jpg
Views:	136
Size:	40.4 KB
ID:	1530665

      My use case is sending an announcement to the player in the foyer when someone enters the outside vestibule. The announcement plays fine and is a 5 second .mp3 file. The error looks like it occurs immediately after the announcement is finished. Debug log file attached.

      There is nothing playing on the player when the announcement is sent the device status of the player before and after the announcement is:

      { "state": "Stopped", "source": "", "sourceExt": "", "currentTrackInfo": { "track": "N/A", "album": "N/A", "artist": "N/A", "art": "N/A" }, "nextTrackInfo": { "track": "N/A", "album": "N/A", "artist": "N/A", "art": "N/A" }, "pairingInfo": null }

      Could it be that the PI is trying to tell the player to play what it was playing before the announcement, which in this case is N/A ?

      Thanks in advance,
      Craig

      Comment


        #4
        Originally posted by dcorsus View Post
        The get picture error is caused because the player tells the PI where the art can be retrieved, but as you can see it is a CDN site that probably timed out the content.
        Second error, this happened due to a pause ALL command that is sent to a player that is most likely idle and therefore doesn't like to be told what to do.
        The last one is of more concern. Do you see more of those. It could indicate your radiostation DB is corrupt or opened by something else or you have no access rights (ex not running as admin).
        Hi Dirk, yikes - I totally forgot to reply! Thanks for the info. I'm taking your comments into consideration as I watch things over time.

        Regarding the RadioStation db error, the DB was created fresh when I installed the plugin. I'll try deleting and recreating it to see if that resolves the issue. Fortunately, we only occasionally memorize stations.
        Best regards,
        -Mark-

        If you're not out on the edge, you're taking up too much room!
        Interested in 3D maps? Check out my company site: Solid Terrain Modeling

        Comment


          #5
          Originally posted by garciacg View Post
          I'm seeing a uPNP error in my logs as well. I'm running the PI version 4.0.1.12 also. The error is repeatable.


          Click image for larger version

Name:	Screenshot 2022-03-07 071343.jpg
Views:	136
Size:	40.4 KB
ID:	1530665

          My use case is sending an announcement to the player in the foyer when someone enters the outside vestibule. The announcement plays fine and is a 5 second .mp3 file. The error looks like it occurs immediately after the announcement is finished. Debug log file attached.

          There is nothing playing on the player when the announcement is sent the device status of the player before and after the announcement is:

          { "state": "Stopped", "source": "", "sourceExt": "", "currentTrackInfo": { "track": "N/A", "album": "N/A", "artist": "N/A", "art": "N/A" }, "nextTrackInfo": { "track": "N/A", "album": "N/A", "artist": "N/A", "art": "N/A" }, "pairingInfo": null }

          Could it be that the PI is trying to tell the player to play what it was playing before the announcement, which in this case is N/A ?

          Thanks in advance,
          Craig
          Do you see this erorr with debug level set to errors only? I tried as much as to not log errors which I think are 100% benign.
          Sometimes a player does not like to be told to restore what it might have been doing at some point in time. Simple test is, play something on that player, pause it and now try your announcement again.

          Comment


            #6
            Hi Dick. I got the error in Debug Level "Errors Only". That's what prompted me to turn on verbose debug to see what was happening. I did as you suggested and played a song from Spotify on that player. Then triggered the announcement event. The announcement played fine but the player never resumed playing and I got the same error as above.

            The device status on that player was still showing this when something was playing or not:

            { "state": "Stopped", "source": "", "sourceExt": "", "currentTrackInfo": { "track": "N/A", "album": "N/A", "artist": "N/A", "art": "N/A" }, "nextTrackInfo": { "track": "N/A", "album": "N/A", "artist": "N/A", "art": "N/A" }, "pairingInfo": null }

            Thinking it might be unique to Spotify as the source, I had the player play something from my local library. Same thing. This suggests the PI isn't tracking the state of the player. My plug-in is a migration from the HS3 version. Perhaps a migration gone bad? I am certain I didn't have these issues before then, so perhaps I should delete everything and start from scratch and see what happens. I have 7 players but fortunately I don't have a lot of events that would be impacted.

            I began running HS4 as a windows service over the last few weeks and began having problems with my scripts which I have since resolved. Since I can't confirm exactly when the errors began happening, I can't tie them to that change. I had post about this elsewhere on the forum.

            https://forums.homeseer.com/forum/ho...69#post1529969

            I'm thinking my best course of action is to delete and rebuild the devices in the PI running HS4 as a service. If I still get errors, I'll runHS4 conventionally and see what happens.

            Thoughts?

            Comment


              #7
              Originally posted by garciacg View Post

              Thinking it might be unique to Spotify as the source, I had the player play something from my local library. Same thing. This suggests the PI isn't tracking the state of the player. My plug-in is a migration from the HS3 version. Perhaps a migration gone bad? I am certain I didn't have these issues before then, so perhaps I should delete everything and start from scratch and see what happens. I have 7 players but fortunately I don't have a lot of events that would be impacted.
              So looking at the source it was on before the announcement would have been the second item to look at.
              Now do not delete anything, that usually makes things worse. So before we go there:
              1. When you use your Sonos APP and play/pause a player, do you see the device state being autonomously updated in the HS4 devices page?
              2. If you don't, did you grant firewall access for the Sonos4 plugin?
              3. I noted you run it as a service, are you sure HS is running as admin and you are NOT using a different working directory from the HS root directory
              4. If you still see nothing wrong, if you go to the settings/Player table, is everything kosher there?
              5. If all looks ok, but have no updates, do you use VMs or managed switches in your network.



              Comment


                #8
                In paralell, set the plugin debug function level to events and errors (nothing else!!), do the event and post the log indicating the error,

                Comment


                  #9
                  Thanks Dick. Your steps 1 - 5 landed me on the problem and the solution.

                  1. The HS4 devices were not updating when controlling via the Sonos APP
                  2. The firewall was granting access to Private Networks but blocking Public Networks. I granted access to Public Networks and everything began working as it should. Errors are gone.
                  3. HS is running as Local System when viewing Services via the services.msc console I'm assuming Local System has admin rights?
                  4. Player table is (and was) kosher
                  5. No VM's or managed switches

                  All seems good now.

                  Thanks again,
                  Craig

                  Comment

                  Working...
                  X