You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@felix.apache.org by Daniel Felsing <da...@maven.at> on 2008/08/04 11:30:04 UTC

Re: Re: Re: UPnP Basedriver 0.8.0 from felix - Devices get lost after a certain period of time...(basedriver locks up) - found the problem - please help!

Hi all,

i really hope so.

A)
the related jira thread is as follows:
https://issues.apache.org/jira/browse/FELIX-657


B)
please take also a look at "upnp event delivery to OSGi event listeners
fails on random devices after a certain period of time"
(=https://issues.apache.org/jira/browse/FELIX-642)
i was not able to resolve this issue yet :-((((


A) this problem is easy to resolve, cause i found it
B) is a real blocker for me right now :-/ so it would be helpful to help
me on that too



Kind regards,
Daniel Felsing



-------------------------------------------
>Hi Daniel,

>yes, probably you 've hit the nail in the head.
>As usual open another issue in JIRA.
>We will help you with the building process after checking the code.

>thanks for your help,
>francesco


On 8/3/2008, "Daniel Felsing" <[EMAIL PROTECTED]> wrote:

>Hello all (and especially to Mr. Lenzi and Mr. Furfari :-),
>
>
>Ok.. i run a test as follows and i think i have pinned down the problem.
>I have everything properly configured...and as i wrote two hosts A and B.
>Both hosts are running OSGi with UPnPBasedriver 0.8.
>Host A exports about 20 devices, host B imports them and acts as a central
>server.
>
>
>Ok...everything runs fine for about 8 hours now. After that i get the
>following:
>
>CyberDomo warning: too many open files
>Java.net.SocketException: Too many open files
>
>That happens in SSDPNotifySocket....in the Device.announce method of
>cybergarage upnp library and that in the thread "Advertiser" on line 68
>
>
>
>----------->
>Under Linux Systems every Socket uses a "file descriptor" in the system
>which is in most unix systems default value of 1024 max descriptors.
>Now i tried to push that value to 65535 and vuala everything is running > 8
>hours.
>
>If i check my open file descriptors with lsof -p pidofmyjavaprogram i see
>now MANY open ports that have not been closed properly (right now > 1400 for
>10 hours of operation).
>
>Ok..that made me let a bit deeper into the code of cyberlink library.
>
>I saw a fix that was introduced by someone because of "non-closed" ssdp udp
>sockets in the announce method of org/cybergarage/upnp/Device.java
>
>1240           SSDPNotifySocket ssdpSock = new SSDPNotifySocket(bindAddr);
> 1241
> 1242          SSDPNotifyRequest ssdpReq = new SSDPNotifyRequest();
> 1243          ssdpReq.setServer(UPnP.getServerName());
> 1244          ssdpReq.setLeaseTime(getLeaseTime());
> 1245          ssdpReq.setLocation(devLocation);
> 1246          ssdpReq.setNTS(NTS.ALIVE);
> 1247
> 1248          // uuid:device-UUID(::upnp:rootdevice)*
> 1249          if (isRootDevice() == true) {
> 1250                  String devNT = getNotifyDeviceNT();
> 1251                  String devUSN = getNotifyDeviceUSN();
> 1252                  ssdpReq.setNT(devNT);
> 1253                  ssdpReq.setUSN(devUSN);
> 1254                  ssdpSock.post(ssdpReq);
> 1255
> 1256                  String devUDN = getUDN();
> 1257                  ssdpReq.setNT(devUDN);
> 1258                  ssdpReq.setUSN(devUDN);
> 1259                  ssdpSock.post(ssdpReq);
> 1260          }
> 1261
> 1262          //
>uuid:device-UUID::urn:schemas-upnp-org:device:deviceType:v
> 1263          String devNT = getNotifyDeviceTypeNT();
> 1264          String devUSN = getNotifyDeviceTypeUSN();
> 1265          ssdpReq.setNT(devNT);
> 1266          ssdpReq.setUSN(devUSN);
> 1267          ssdpSock.post(ssdpReq);
> 1268
> 1269          // Thanks for Mikael Hakman (04/25/05)
> 1270          ssdpSock.close();
>
>Ok seems fine so far...
>
>
>Ok now i looked into org/cybergarage/upnp/Service.java and there the "socket
>close fix" was NOT introduced for both announce and byebye.....
>
>  599  public void announce(String bindAddr)
>  600  {
>  601          //
>uuid:device-UUID::urn:schemas-upnp-org:service:serviceType:v
>  602          Device rootDev = getRootDevice();
>  603          String devLocation = rootDev.getLocationURL(bindAddr);
>  604          String serviceNT = getNotifyServiceTypeNT();
>  605          String serviceUSN = getNotifyServiceTypeUSN();
>  606
>  607          Device dev = getDevice();
>  608
>  609          SSDPNotifyRequest ssdpReq = new SSDPNotifyRequest();
>  610          ssdpReq.setServer(UPnP.getServerName());
>  611          ssdpReq.setLeaseTime(dev.getLeaseTime());
>  612          ssdpReq.setLocation(devLocation);
>  613          ssdpReq.setNTS(NTS.ALIVE);
>  614          ssdpReq.setNT(serviceNT);
>  615          ssdpReq.setUSN(serviceUSN);
>  616
>  617          SSDPNotifySocket ssdpSock = new SSDPNotifySocket(bindAddr);
>  618          Device.notifyWait();
>  619          ssdpSock.post(ssdpReq);
>  620  }
>
>
>  622  public void byebye(String bindAddr)
>  623  {
>  624          //
>uuid:device-UUID::urn:schemas-upnp-org:service:serviceType:v
>  625
>  626          String devNT = getNotifyServiceTypeNT();
>  627          String devUSN = getNotifyServiceTypeUSN();
>  628
>  629          SSDPNotifyRequest ssdpReq = new SSDPNotifyRequest();
>  630          ssdpReq.setNTS(NTS.BYEBYE);
>  631          ssdpReq.setNT(devNT);
>  632          ssdpReq.setUSN(devUSN);
>  633
>  634          SSDPNotifySocket ssdpSock = new SSDPNotifySocket(bindAddr);
>  635          Device.notifyWait();
>  636          ssdpSock.post(ssdpReq);
>  637  }
>
>
>
>
>
>So .... may this be the root of the problem?
>So if it is...i am very bad in using pom.xml files to build the basedriver
>against the latest cyberlink library :-((((((
>
>So Question A is: can mr lenzi and mr furfari confirm this as a bug and the
>cause of my problem?
>And Question B is: could one of you please please fix it, build me the
>basedriver against the fixed code and send it to me? :-/
>Or just update the pom.xml and the sourcecode so i can build it using the
>"apache felix" maven repository
>
>
>
>Kind regards and MANY MANY thanks in advance,
>       Daniel Felsing
>
>
>
>-----Ursprüngliche Nachricht-----
>Von: Daniel Felsing [EMAIL PROTECTED]
>Gesendet: Freitag, 01. August 2008 08:46
>An: 'users@felix.apache.org'
>Betreff: Re: Re: UPnP Basedriver 0.8.0 from felix - Devices get lost after a
>certain period of time...(basedriver locks up)
>
>Hi again,
>
>i just checked the active ethernet links via ifconfig.
>
>Eth0 and eth1
>One is the cable connection, the second wlan.
>
>I have not configured wlan since i use cable connection for programming - it
>seems that one of those ip addresses is selected randomly in the base
>driver.
>The dhcp is properly running though.
>
>
>I just deactivated the wlan address...now i'm curious what is happening :-)
>Since this can be the only fault on my side which is causing that prob.
>
>Kind regards,
>Daniel
>
>-----Ursprüngliche Nachricht-----
>Von: Remco Poortinga [EMAIL PROTECTED]
>Gesendet: Freitag, 01. August 2008 08:40
>An: users@felix.apache.org
>Betreff: RE: Re: UPnP Basedriver 0.8.0 from felix - Devices get lost after a
>certain period of time...(basedriver locks up)
>
>Hi Daniel,
>
>IP(v4) addresses in the 196.254.0.0/16 range are link-local IP
>addresses.
>These are (obviously) not routable beyond link scope, but probably do
>show up because of the UPnP bridge?
>(that is: the bridge does see them at that location and just reports
>that)
>
>These addresses are often used as an address when e.g. DHCP fails (so if
>a machine boots up, but can't find a place to get an address from, it
>will use an address from this range).
>Since your problems (if I understand correctly) don't happen directly
>from the start, maybe there's an issue with DHCP when a lease expires?
>
>Just guessing here, and of course these addresses showing up might not
>be related to/causing your problem at all;  but might be worth
>exploring.
>
>Best regards,
>
>Remco
>
>> -----Original Message-----
>> From: Daniel Felsing [EMAIL PROTECTED]
>> Sent: Friday, August 01, 2008 8:25 AM
>> To: users@felix.apache.org
>> Subject: Re: Re: UPnP Basedriver 0.8.0 from felix - Devices
>> get lost after a certain period of time...(basedriver locks up)
>>
>> Hello again....
>>
>>
>> A follow up to the below - remember the ip address of the
>> host exporting the devies is 192.168.0.9, the importer host
>> is 192.168.0.5 Notice the differences in the Location
>> line....sometimes a very weird ip address shows up...and
>> sometimes the importer host is shown.
>>
>>
>> Sometimes i see:
>>
>> --------------------------------------------
>> debug    20080801 08:17:37 bid#94       - [Importer]
>> ssdpPacket.isAlive
>> debug    20080801 08:17:37 bid#94       - [Importer] Device already
>> discovered
>> debug    20080801 08:17:37 bid#94       - [Importer] check for service
>> updating
>> debug    20080801 08:17:37 bid#94       - [Importer]
>> deviceNotifyReceived
>> debug    20080801 08:17:37 bid#94       -
>> ================REQUEST=====================
>> NOTIFY * HTTP/1.1
>> Server: Linux/2.6.20-17-generic UPnP/1.0 CyberDomo/1.8
>> Cache-Control: max-age=1800
>> Location: http://169.254.5.186:4020/gen-desc.xml
>> NTS: ssdp:alive
>> NT: urn:schemas-upnp-org:service:GetLevel:1
>> USN:
>> uuid:AT-SM-FHZ1-S20_Switch2::urn:schemas-upnp-org:service:GetLevel:1
>> HOST: 239.255.255.250:1900
>>
>>
>> And sometimes:
>>
>> --------------------------------------------
>> debug    20080801 08:19:10 bid#94       - [Importer]
>> ssdpPacket.isAlive
>> debug    20080801 08:19:10 bid#94       - [Importer] Device already
>> discovered
>> debug    20080801 08:19:10 bid#94       - [Importer] check for service
>> updating
>> debug    20080801 08:19:10 bid#94       - [Importer]
>> deviceNotifyReceived
>> debug    20080801 08:19:10 bid#94       -
>> ================REQUEST=====================
>> NOTIFY * HTTP/1.1
>> Server: Linux/2.6.20-17-generic UPnP/1.0 CyberDomo/1.8
>> Cache-Control: max-age=1800
>> Location: http://192.168.0.5:4007/gen-desc.xml
>> NTS: ssdp:alive
>> NT: upnp:rootdevice
>> USN: uuid:AT-SM-FHZ1-S20_Switch1::upnp:rootdevice
>> HOST: 239.255.255.250:1900
>>
>>
>>
>>
>> Here agaain:
>> --------------------------------------------
>> debug    20080801 08:21:05 bid#94       - [Importer]
>> ssdpPacket.isAlive
>> debug    20080801 08:21:05 bid#94       - [Importer] Device already
>> discovered
>> debug    20080801 08:21:05 bid#94       - [Importer] check for service
>> updating
>> debug    20080801 08:21:05 bid#94       - [Importer]
>> deviceNotifyReceived
>> debug    20080801 08:21:05 bid#94       -
>> ================REQUEST=====================
>> NOTIFY * HTTP/1.1
>> Server: Linux/2.6.20-17-generic UPnP/1.0 CyberDomo/1.8
>> Cache-Control: max-age=1800
>> Location: http://169.254.5.186:4021/gen-desc.xml
>> NTS: ssdp:alive
>> NT: urn:schemas-upnp-org:service:SwitchDevice:1
>> USN:
>> uuid:AT-SM-FHZ1-shutter1::urn:schemas-upnp-org:service:SwitchDevice:1
>> HOST: 239.255.255.250:1900
>>
>>
>> --------------------------------------------
>> debug    20080801 08:22:19 bid#94       - [Importer]
>> ssdpPacket.isAlive
>> debug    20080801 08:22:19 bid#94       - [Importer] Device already
>> discovered
>> debug    20080801 08:22:19 bid#94       - [Importer]
>> deviceNotifyReceived
>> debug    20080801 08:22:19 bid#94       -
>> ================REQUEST=====================
>> NOTIFY * HTTP/1.1
>> Server: Linux/2.6.20-17-generic UPnP/1.0 CyberDomo/1.8
>> Cache-Control: max-age=1800
>> Location: http://169.254.5.186:4005/gen-desc.xml
>> NTS: ssdp:alive
>> NT: uuid:AT-SM-FHZ1-rainsensor1
>> USN: uuid:AT-SM-FHZ1-rainsensor1
>> HOST: 239.255.255.250:1900
>>
>>
>> --------------------------------------------
>> debug    20080801 08:21:46 bid#94       - [Importer]
>> ssdpPacket.isAlive
>> debug    20080801 08:21:46 bid#94       - [Importer] Device already
>> discovered
>> debug    20080801 08:21:46 bid#94       - [Importer]
>> deviceNotifyReceived
>> debug    20080801 08:21:46 bid#94       -
>> ================REQUEST=====================
>> NOTIFY * HTTP/1.1
>> Server: Linux/2.6.20-17-generic UPnP/1.0 CyberDomo/1.8
>> Cache-Control: max-age=1800
>> Location: http://192.168.0.5:4012/gen-desc.xml
>> NTS: ssdp:alive
>> NT: urn:schemas-upnp-org:device:FHZDimmingSwitch:1
>> USN:
>> uuid:AT-SM-FHZ1-S20_Switch8::urn:schemas-upnp-org:device:FHZDi
>mmingSwitch:1
>> HOST: 239.255.255.250:1900
>>
>> -----Ursprüngliche Nachricht-----
>> Von: Daniel Felsing [EMAIL PROTECTED]
>> Gesendet: Freitag, 01. August 2008 08:13
>> An: users@felix.apache.org
>> Betreff: Re: UPnP Basedriver 0.8.0 from felix - Devices get
>> lost after a certain period of time...(basedriver locks up)
>>
>> Hello,
>>
>> a small follow up - maybe this causes the problem?
>> This shows the discovery of a specific upnp device, which is
>> then refined.
>> What makes me wonder is the proposed location which is wrong:
>> Location:
>> http://169.254.5.186:4009/gen-desc.xml
>> If you look at the 2nd message which delivers me the event
>> the ip address of the host is correct: HOST: 192.168.0.9
>>
>>
>> debug    20080801 08:08:51 bid#102      -
>> at.smarthome.fhzupnprefiningdriver.FHZRefiningDriverImpl[FHZRe
>> finingDriver
>> match method called for DEVICE_CATEGORY: UPnP]
>> info     20080801 08:08:51 bid#94       -
>> [56;org.osgi.service.upnp.UPnPDevice] ServiceEvent REGISTERED
>> debug    20080801 08:08:51 bid#102      -
>> at.smarthome.fhzupnprefiningdriver.FHZRefiningDriverImpl[Match
>> ed device:
>> uuid:AT-SM-FHZ1-dimmablelight1 of model type FHZDimmableLight]
>> debug    20080801 08:08:51 bid#94       - [Importer] searching for
>> UPnPEventListener
>> debug    20080801 08:08:51 bid#102      -
>> at.smarthome.fhzupnprefiningdriver.FHZRefiningDriverImpl[FHZRe
>> finingDriver
>> attach method called for DEVICE_CATEGORY: UPnP]
>> info     20080801 08:08:51 bid#102      -
>> at.smarthome.fhzupnprefiningdriver.FHZRefiningDriverImpl[Attac
>> hing to device with UDN: uuid:AT-SM-FHZ1-dimmablelight1 of
>> model type FHZDimmableLight]
>> debug    20080801 08:08:51 bid#102      -
>> at.smarthome.fhzupnprefiningdriver.FHZRefiningDriverImpl[at.sm
>> arthome.fhzupn
>> prefiningdriver 1.0 creating new DimmableLight Device]
>> debug    20080801 08:08:51 bid#94       - [Importer]
>> deviceSearchResponseReceived
>> debug    20080801 08:08:51 bid#94       -
>> ================REQUEST=====================
>> HTTP/1.1 200 OK
>> Content-Type: text/html; charset="utf-8"
>> Server: Linux/2.6.20-17-generic UPnP/1.0 CyberDomo/1.8
>> Content-Length: 0
>> Cache-Control: max-age=1800
>> EXT:
>> Date: Fri, 01 Aug 2008 08:05:56 GMT
>> ST: upnp:rootdevice
>> USN: uuid:AT-SM-FHZ1-S20_Switch4::upnp:rootdevice
>> Location: http://169.254.5.186:4009/gen-desc.xml
>> MYNAME: FHZDimmingSwitch
>>
>> --------------------------------------------
>>
>> debug    20080801 08:08:51 bid#94       -
>> Event::org.osgi.framework.ServiceEvent[source={org.osgi.servic
>> e.upnp.UPnPEve
>> ntListener}={upnp.filter=(UPnP.device.UDN=uuid:AT-SM-FHZ1-dimm
>ablelight1),
>> service.id=57}]
>> debug    20080801 08:08:52 bid#94       - [Importer]
>> httpRequestRecieved
>> event
>> debug    20080801 08:08:52 bid#94       -
>> ================REQUEST=====================
>> NOTIFY /evetSub HTTP/1.0
>> Content-Type: text/xml; charset="utf-8"
>> HOST: 192.168.0.9
>> NT: upnp:event
>> NTS: upnp:propchange
>> SID: uuid:5cca-a11b-f11d-e0c2
>> SEQ: 0
>> Content-Length: 165
>> Connection: close
>>
>> <?xml version="1.0" encoding="utf-8"?>
>> <propertyset xmlns:e="urn:schemas-upnp-org:event-1-0">
>>    <property>
>>       <Status>off</Status>
>>    </property>
>> </propertyset>
>> --------------------------------------------
>>
>>
>> Kind regards,
>> Daniel Felsing
>>
>>
>> -----Ursprüngliche Nachricht-----
>> Von: Daniel Felsing [EMAIL PROTECTED]
>> Gesendet: Freitag, 01. August 2008 08:03
>> An: users@felix.apache.org
>> Cc: 'Francesco Furfari'; 'Stefano "Kismet" Lenzi'
>> Betreff: UPnP Basedriver 0.8.0 from felix - Devices get lost
>> after a certain period of time...(basedriver locks up)
>>
>> Hello all,
>>
>>
>>
>> I already published that in another post but since it is a
>> new topic / problem i summarise my architecture.
>>
>>
>>
>> I have 2 hosts A and B. Both are running UPnP Basedriver to
>> access the upnp network.
>>
>>
>>
>>
>>
>> Host A acts as a upnp bridge to export X10 like devices
>> (Switches, Motionsensors, Lights etc.) into the upnp network.
>> Right now 19 devices get exported.
>>
>> I'm using the helper class UPnPEventNotifier there.
>>
>>
>>
>> Host B acts as a central server which imports and refines
>> those devices (using a refining driver) using the base driver.
>>
>> The refined devices use UPnPSubscriber to subscribe to UPnP
>> Events and get status updates of the devices.
>>
>>
>>
>>
>>
>> Host A and B are connected through a gigabit switch, so no
>> wireless or anything other in between.
>>
>>
>>
>>
>>
>> After a random time - say 30-50 minutes - it often occur that
>> devices just unregister and disappear.
>>
>> I refer to the topic of the domoware site since the guy there
>> had a similiar problem and maybe mr lenzi and mr furfari can
>> remember that:
>>
>> https://sourceforge.net/forum/forum.php?thread_id=1871253
>> <https://sourceforge.net/forum/forum.php?thread_id=1871253&for
>um_id=406095>
>> &forum_id=406095
>>
>>
>>
>>
>>
>> ok - the other guy was using devices that were not exported
>> by the upnp basedriver.i'm only using devices that get
>> exported by upnp base driver from felix.
>>
>> That's the difference.
>>
>>
>>
>>
>>
>> I tried the solution explained there to use the
>> DriverController.search method to propagate msearches for all
>> devices every 10 minutes.
>>
>> After 3 hours of operation doing that the basedriver on Host
>> A (the bridge) begin to lockup. The devices all disappear and
>> i get continous error messages
>>
>> by Cyberdomo saying "Too many files open".
>>
>>
>>
>>
>>
>> So to summarise my problem:
>>
>>
>>
>> a)      The renewal of devices without m-search using the
>> base-driver on
>> both ends doesn't seem to work properly, since after some
>> time devices disappear. (however all is working fine for some time)
>>
>> b)       After doing m-searches the basedriver is getting
>> unstable saying
>> "too many files open"
>>
>>
>>
>>
>>
>> I really need help.
>>
>>
>>
>>
>>
>> Kind regards,
>>
>> Daniel Felsing
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [EMAIL PROTECTED]
>> For additional commands, e-mail: [EMAIL PROTECTED]
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [EMAIL PROTECTED]
>> For additional commands, e-mail: [EMAIL PROTECTED]
>>
>>
>
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: [EMAIL PROTECTED]
>For additional commands, e-mail: [EMAIL PROTECTED]
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@felix.apache.org
For additional commands, e-mail: users-help@felix.apache.org