Potential Memory leak? (Sonos?)

[Andre Dieball]

Hi

since a couple of days my openhab crashes after a couple of hours with a memory problem:

2015-02-19 07:57:59.995 [INFO ] [.b.sonos.internal.SonosBinding] - Found a Sonos device (S1) with UDN uuid:RINCON_B8E93783C03801400
2015-02-19 07:58:38.791 [INFO ] [.b.sonos.internal.SonosBinding] - A non-Sonos device (Plex, Inc. Plex Media Server 0.9.9.7) is found and will be ignored
2015-02-19 07:58:50.066 [INFO ] [.b.sonos.internal.SonosBinding] - Found a Sonos device (Sub) with UDN uuid:RINCON_000E589D607E01400
2015-02-19 08:00:06.951 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:00:06.958 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:00:07.018 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:00:07.020 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:14:36.958 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:14:36.962 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:14:37.055 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:14:37.057 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:23:31.284 [WARN ] [sonos.internal.SonosZonePlayer] - Current state of service prevents invoking that action. Connection error or no response received.
2015-02-19 08:29:06.965 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:29:06.968 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:29:07.062 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:29:07.064 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:43:37.010 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:43:37.012 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:43:38.118 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:43:38.120 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 08:55:15.970 [INFO ] [.service.AbstractActiveService] - Withings Refresh Service has been shut down
2015-02-19 08:58:08.191 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 08:58:08.194 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 09:12:37.343 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 09:12:37.352 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 09:27:07.215 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 09:27:07.231 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 09:41:37.103 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 09:41:37.106 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 09:41:37.165 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 09:41:37.167 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 09:56:07.119 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 09:56:07.122 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 09:56:07.188 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 09:56:07.208 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 10:07:30.639 [WARN ] [sonos.internal.SonosZonePlayer] - Current state of service prevents invoking that action. Connection error or no response received.
2015-02-19 10:10:37.353 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Could not hydrate device or its services from descriptor: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:bc329e00-1dd8-11b2-8601-b0c554074cf3, Descriptor: http://10.2.2.240:49152/webs/description.xml, Root: true
2015-02-19 10:10:37.356 [WARN ] [.c.p.RetrieveRemoteDescriptors] - Cause was: org.teleal.cling.model.types.InvalidValueException: Can't parse Service ID string (namespace/id): urn:Alphanetworks:service:BasicServiceId
2015-02-19 10:12:11.429 [ERROR] [c.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /dev/RINCON_000E589D607E01400/svc/upnp-org/GroupManagement/event/cb.xml SEQUENCE: 0
2015-02-19 10:12:18.536 [ERROR] [c.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /dev/RINCON_B8E93783C03801400/svc/upnp-org/ZoneGroupTopology/event/cb.xml SEQUENCE: 0
2015-02-19 10:12:36.848 [ERROR] [c.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /dev/RINCON_B8E93783C03801400/svc/upnp-org/ZoneGroupTopology/event/cb.xml SEQUENCE: 0
2015-02-19 10:12:43.805 [ERROR] [c.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /dev/RINCON_B8E93783C03801400/svc/upnp-org/GroupManagement/event/cb.xml SEQUENCE: 0
2015-02-19 10:14:14.820 [ERROR] [c.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /dev/RINCON_B8E93783C03801400/svc/upnp-org/GroupManagement/event/cb.xml SEQUENCE: 0
2015-02-19 10:14:28.970 [ERROR] [c.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /dev/RINCON_B8E93783C03801400/svc/upnp-org/ZoneGroupTopology/event/cb.xml SEQUENCE: 0
2015-02-19 10:15:40.709 [WARN ] [efaultUpnpServiceConfiguration] - Thread terminated org.teleal.cling.registry.RegistryMaintainer@56d942 abruptly with exception: java.lang.OutOfMemoryError: unable to create new native thread

I search the net a bit and it looks like a problem with the Sonos binding. One of my Sonos speakers is currently offline, could this be the problem?

Can I upgrade to a new binding version which fixes the issue?

I'm currently running 1.6.1

thanks

Andre

 

[Andre Dieball]

UPDATE:

10.2.2.240 is a DLink Webcam not linked to openhab in any way

Thanks

[Andre Dieball]

bump ...

anyone any idea? I'd really like to avoid using watchdog to reboot the box every 2 hours or so .....

[Jens Kastensson]

For info, I ran OH 1.7 under Windows with plumbr.eu for almost one day, it didn't find any leaks with my config.

Jens 

[Andre Dieball]

There is no 1.7 apt-repo yet (only 1.6.2)

can someone confirm this "bug" is solved in 1.6.2 or do I need to go to 1.7 development release?

thanks

[Andre Dieball]

running 1.7 snapshot since a couple of days now without any issues

[Andre Dieball]

Hi

to early ...

I just happened again :-(

openhab log:

2015-03-14 04:35:28.087 [WARN ] [efaultUpnpServiceConfiguration] - Root cause: java.lang.OutOfMemoryError: unable to create new native thread
Exception in thread "cling-25031" Exception in thread "cling-23166" Exception in thread "cling-25476" 2015-03-14 04:35:28.117 [WARN ] [efaultUpnpServiceConfiguration] - Thread terminated (SendingRenewal) abruptly with exception: java.lang.OutOfMemoryError: unable to create new native thread
2015-03-14 04:35:28.133 [WARN ] [efaultUpnpServiceConfiguration] - Root cause: java.lang.OutOfMemoryError: unable to create new native thread
Exception in thread "cling-25028" Exception in thread "cling-25025" Exception in thread "cling-25020" Exception in thread "cling-25465" Exception in thread "cling-25026" Exception in thread "cling-25467" Exception in thread "cling-25463" Exception in thread "cling-25462" Exception in thread "cling-25460" Exception in thread "cling-25457" Exception in thread "cling-25456" Exception in thread "cling-25455" Exception in thread "cling-25453" Exception in thread "cling-25454" Exception in thread "cling-25449" Exception in thread "cling-24993" Exception in thread "cling-24992" Exception in thread "cling-24990" Exception in thread "cling-24989" Exception in thread "cling-24988" Exception in thread "cling-24984" Exception in thread "cling-24991" Exception in thread "cling-24985" Exception in thread "cling-24983" Exception in thread "cling-24981" Exception in thread "cling-25435" Exception in thread "cling-24982" Exception in thread "cling-24978" #
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 32756 bytes for ChunkPool::allocate
# An error report file with more information is saved as:
# /opt/openhab/hs_err_pid31009.log

the error log:

#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 32756 bytes for ChunkPool::allocate
# Possible reasons:
#   The system is out of physical RAM or swap space
#   In 32 bit mode, the process size limit was hit
# Possible solutions:
#   Reduce memory load on the system
#   Increase physical memory or swap space
#   Check if swap backing store is full
#   Use 64 bit Java on a 64 bit OS
#   Decrease Java heap size (-Xmx/-Xms)
#   Decrease number of Java threads
#   Decrease Java thread stack sizes (-Xss)
#   Set larger code cache with -XX:ReservedCodeCacheSize=
# This output file may be truncated or incomplete.
#
#  Out of Memory Error (allocation.cpp:273), pid=31009, tid=2746078320
#
# JRE version: Java(TM) SE Runtime Environment (8.0_33-b05) (build 1.8.0_33-b05)
# Java VM: Java HotSpot(TM) Client VM (25.33-b05 mixed mode linux-arm )
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#


---------------  T H R E A D  ---------------


Current thread (0x02bfbc00):  VMThread [stack: 0xa3a5e000,0xa3ade000] [id=31011]


Stack: [0xa3a5e000,0xa3ade000]
VM_Operation (0xbcdaf84c): BulkRevokeBias, mode: safepoint, requested by thread 0x718f9c00




---------------  P R O C E S S  ---------------


Java Threads: ( => current thread )
  0xb71c3c00 JavaThread "cling-25593" [_thread_blocked, id=8670, stack(0xbef72000,0xbefc2000)]
  0xb71c2000 JavaThread "cling-25594" [_thread_blocked, id=8669, stack(0xbef22000,0xbef72000)]
  0xb71c0800 JavaThread "cling-25595" [_thread_blocked, id=8668, stack(0xbeed2000,0xbef22000)]
  0xb71bf000 JavaThread "cling-25591" [_thread_blocked, id=8667, stack(0xbee82000,0xbeed2000)]
  0x71b6d800 JavaThread "cling-25597" [_thread_blocked, id=8666, stack(0xbee32000,0xbee82000)]
  0x71b6c000 JavaThread "cling-25598" [_thread_blocked, id=8665, stack(0xbede2000,0xbee32000)]
  0xb71bd400 JavaThread "cling-25600" [_thread_blocked, id=8664, stack(0xbed92000,0xbede2000)]
  0xb71bbc00 JavaThread "cling-25601" [_thread_blocked, id=8663, stack(0xbed42000,0xbed92000)]
  0x71b6a800 JavaThread "cling-25603" [_thread_blocked, id=8662, stack(0xbecf2000,0xbed42000)]
  0x71b69000 JavaThread "cling-25605" [_thread_blocked, id=8661, stack(0xbeca2000,0xbecf2000)]
  0xb71ba000 JavaThread "cling-25606" [_thread_blocked, id=8660, stack(0xbec52000,0xbeca2000)]
  0xb71b8c00 JavaThread "cling-25608" [_thread_blocked, id=8659, stack(0xbec02000,0xbec52000)]
  0xb71b7400 JavaThread "cling-25609" [_thread_blocked, id=8658, stack(0xbebb2000,0xbec02000)]
  0xb71b5800 JavaThread "cling-25610" [_thread_blocked, id=8657, stack(0xbeb62000,0xbebb2000)]
  0xb71b4400 JavaThread "cling-25611" [_thread_blocked, id=8656, stack(0xbeac1000,0xbeb11000)]
  0xb71b2800 JavaThread "cling-25613" [_thread_blocked, id=8655, stack(0xbea71000,0xbeac1000)]
  0xb71b0800 JavaThread "cling-25614" [_thread_blocked, id=8654, stack(0xbea21000,0xbea71000)]
  0xb71af000 JavaThread "cling-25615" [_thread_blocked, id=8653, stack(0xbe9d1000,0xbea21000)]
  0xb71ad800 JavaThread "cling-25617" [_thread_blocked, id=8652, stack(0xbe981000,0xbe9d1000)]
  0xb71ac000 JavaThread "cling-25619" [_thread_blocked, id=8651, stack(0xbe931000,0xbe981000)]
  0xb71aa800 JavaThread "cling-25620" [_thread_blocked, id=8650, stack(0xbe8e1000,0xbe931000)]
  0x71b67800 JavaThread "cling-25621" [_thread_blocked, id=8649, stack(0xbe891000,0xbe8e1000)]
  0xb71a8800 JavaThread "cling-25622" [_thread_blocked, id=8648, stack(0xbe841000,0xbe891000)]

I just copied the first part as it's quite big. If you need the full file for troubleshooting let me know ...

Thanks

[cal]

Moin,

are you running openHAB on system with limited resources like raspberry Pi?
Looks like you promised more resources to the java process than OS could deliver.
Take a look at the suggestions in log file.
Start with check that java max heap (Parameter -Xmx) is lower than available memory before starting openHAB. You can use free/freemem/top to find out available mem.

Hope that helps,
Carsten

[Andre Dieball]

Moin Carsten

I added -Xmx256 and -Xms256 in eclipse.ini and will monitor the behaviour.

I'm running on a cubietruck with 2GB Ram

Andre

[Andre Dieball]

Setting Xms has not helped, it crashed again tonight.

I now disabled the Sonos bindung and the related items and will watch ..

[Karel Goderis]

Hi

Cling is the underlying UPNP library that is used to communicate with the Sonos players. The error is as such not related to the binding itself. I have not seen it yet on my own system. It is difficult to tell what is the cause here….

Regards

K

--
You received this message because you are subscribed to the Google Groups "openhab" group.
To unsubscribe from this group and stop receiving emails from it, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.
To view this discussion on the web visit https://groups.google.com/d/msgid/openhab/05c01b0e-ec98-4096-b294-4601c80f8316%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[cal]

Looks indeed like a problem others had with cling, too.

http://sourceforge.net/p/subsonic/bugs/115/
http://knx-user-forum.de/forum/supportforen/openhab/37306-upnp-verursacht-outofmemory-exception

Or google for

upnp cling outofmemory

[cal]

Looks like the openHAB sonos bundle uses cling 1.0.5

jar tvf openhab-1.7.0-SNAPSHOT/all-addons/org.openhab.binding.sonos-1.7.0-SNAPSHOT.jar | grep cling
551922 Sun Feb 15 15:17:04 CET 2015 lib/cling-core-1.0.5.jar
359154 Sun Feb 15 15:17:04 CET 2015 lib/cling-support-1.0.5.jar

But current version seems to be 2.0.1: http://4thline.org/projects/cling/

[Andre Dieball]

I have openhab running now for a while without any issues.

Looks like the cling in the sonos binding is causing this issue.

as cal mentioned, it seems to be an "old" version. Has anyone tried the bindung with a new version of cling?

Thanks 

[ResIpsa]

I am seeing a memory leak issue that I believe is coming from the sonos binding.  My openHAB instance typically takes up 250-300MB.  After 2-3 days, its memory usage jumps up to 1.2GB and the sonos binding stops updating the variables (e.g., track, title, etc.).  To the extent it matters, I'm running a recent openHAB 1.7 snapshot on Ubuntu 14.04.  I also had the same issue with versions 1.6.1.

[Konrad Hübner]

Hi, I had been running openhab 1.6.2 with Sonos binding on my Raspberry PI (manual install) for months without issues. After upgrading to apt-package of 1.7.0 I get these out of memory crashes as well, after only two days. This is sort of frustrating. Any ideas so far?

[Oliver Kuhl]

Same here...

Regards

Ollie

[Martin Klimke]

The Sonos binding never worked reliable and with V1.7.1 my openhab became unstable (Window 10 only 1 GB of RAM)

I have given up using the Sonos binding and been using a workaround

https://community.openhab.org/t/sonos-workaround/2513