Losing events on REST API (atmosphere)

[renatoriolino]

Hi guys!

I have built myself a microcontrolled hardware to automate my home and I'm using openhab as a interface.

The server talks with all the controllers via RS-485 and since I don't program in Java, I've made a C program to talk via rs485 with the hardware and via REST API with OpenHab.

Everything is working perfectly with OH 1.3.1 but not with OH 1.4.

With 1.4, I'm losting a lot of events (ex: I change a switch item via HABDroid my C application doesn't receive the update).

For polling the items, I'm using HTTP Header "X-Atmosphere-Transport: streaming".

Every time I lost an event, OH outputs the following on LOG:

00:01:56.844 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=Garagem (Type=SwitchItem, State=OFF), type=ALL, future=org.atmosphere.cpr.BroadcasterFuture@33d1d377} will be lost

Let me know if you need for information.

Thanks

Renato

[belovictor]

Do you see a message like '16:17:05.292 DEBUG o.o.i.r.i.b.GeneralBroadcaster[:41] - broadcaster 'org.openhab.io.rest.internal.broadcaster.GeneralBroadcaster$1@5507f60' is empty' right before the one you specified in your log?

[renatoriolino]

No, I don't see it on logs. Here is a little more log:

00:01:56.844 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=Garagem (Type=SwitchItem, State=OFF), type=ALL, future=org.atmosphere.cpr.BroadcasterFuture@33d1d377} will be lost
00:10:01.386 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=Garagem (Type=SwitchItem, State=ON), type=ALL, future=org.atmosphere.cpr.BroadcasterFuture@48dc7834} will be lost
00:10:05.645 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=Garagem (Type=SwitchItem, State=OFF), type=ALL, future=org.atmosphere.cpr.BroadcasterFuture@3af3987a} will be lost
00:49:04.315 INFO o.o.a.x.internal.XMPPConnect[:199]- XMPP connection has been closed on error: Connection reset
00:49:07.005 INFO o.o.a.x.internal.XMPPConnect[:117]- Connection to XMPP as '[email protected]' has been established.
00:49:07.007 INFO o.o.a.x.internal.XMPPConnect[:205]- XMPP re-connection succeeded.
00:51:02.178 WARN o.o.b.xbmc.rpc.XbmcConnector[:107]- Websocket closed.
00:51:02.186 WARN c.n.h.c.p.n.NettyAsyncHttpProvider[:2415]- onError [id: 0x7c9d1d54, /192.168.25.22:32934 :> /192.168.25.24:9090] EXCEPTION: org.jboss.netty.handler.codec.frame.CorruptedFrameException: invalid UTF-8 bytes
01:00:00.009 INFO org.openhab.model.script.temp[:53]- Resetando temperatura
01:52:46.782 WARN o.o.u.i.i.ItemUIRegistryImpl[:434]- Cannot find page for id 'renato'.
01:55:59.057 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=CorredorPequeno (Type=SwitchItem, State=ON), type=ALL, future=org.atmosphere.cpr.BroadcasterFuture@1348471} will be lost
01:57:18.253 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=CorredorPequeno (Type=SwitchItem, State=OFF), type=ALL, future=org.atmosphere.cpr.BroadcasterFuture@70471c9a} will be lost
02:00:00.008 INFO org.openhab.model.script.temp[:53]- Resetando temperatura
02:15:12.833 WARN o.o.u.i.i.ItemUIRegistryImpl[:434]- Cannot find page for id 'renato'.
02:15:29.903 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=org.openhab.io.rest.internal.resources.beans.PageBean@6e3dae12, type=RESOURCE, future=org.atmosphere.cpr.BroadcasterFuture@3afaa77b} will be lost

The log's settings are at defaults. Do I have to change any settings to enable more debug info on logs?

Thanks.

[renatoriolino]

Hi again!

Looking at other issues, I found issue 673 to be almost the same:

#673

[oliver-M]

Hi,
can you post a complete HTTP request from your C application?

[renatoriolino]

I use libcurl for the request. Here I setup the headers:

    i->headers = curl_slist_append(i->headers, "Content-Type: text/html");
    i->headers = curl_slist_append(i->headers, "X-Atmosphere-Transport: streaming");
    snprintf(strAux, 64, "X-Atmosphere-tracking-id: %d", getpid() + cnt++);
    i->headers = curl_slist_append(i->headers, strAux);
    curl_easy_setopt(i->handle, CURLOPT_HTTPHEADER, i->headers);

The URL is defined here:

    curl_easy_setopt(i->handle, CURLOPT_URL, i->link);

where i->link is:

http://192.168.25.26:8080/rest/items/Garagem

When the item gets updated, my handle function uses libxml to parse the status change (but this function is never called when the lost event happens):

XMLDocument doc;
doc.Parse(p);
XMLElement *item = doc.FirstChildElement("item");
if (item != NULL)
    // proccess here the status change

Please let me know if you need more information.

Thanks

[oliver-M]

Ok, seems that openHab doesn't know how to answer your request. The "accept" HTTP header is missing.
Please add "Accept: application/xml" to receive messages in XML format or "Accept: application/json" if you want a message in JSON format.

[renatoriolino]

@oliver-M, thank you.

After adding the http header "Accept: application/xml" no events was lost anymore. I'm still having other issues with 1.4 but I'll post on another topic.

Thanks again!

[renatoriolino]

Unfortunately the lost events issue persist. I updated OH 1.4 to build 594 and I'm sending the header "Accept: application/xml", but I'm still losing events:

15:17:15.625 WARN o.a.cpr.DefaultBroadcaster[:500]- This message Entry{message=HomeCentral (Type=SwitchItem, State=ON), type=ALL, future=org.atmosphere.cpr.
BroadcasterFuture@13b0c03} will be lost

Which debug should I enable to help hunt this bug?

Thanks

[peuter]

I just tried to investigate this problem. It seems to be a problem with the streaming transport, when I use long-polling I get proper updates of the items. Please verify by comparing the results of these two queries:

curl --header "X-Atmosphere-Transport: long-polling" --header "Accept: application/json" http://192.168.25.26:8080/rest/items/Garagem

curl --header "X-Atmosphere-Transport: streaming" --header "Accept: application/json" http://192.168.25.26:8080/rest/items/Garagem

From my point of view this has nothing to do with the DefaultBroadcasters losing events log entries. There is rather some mistake in generating the response in streaming transport mode.

[oliver-M]

I will try to reproduce your findings..

[peuter]

I upgraded the atmosphere libs to the current version 2.1.1 and the streaming transport seems to be working again. Maybe you could test this against your setup, you can find my clone here:
https://github.com/peuter/openhab

There is one problem that needs to be resolved before I can create a pull request: During start I get the following exception for all rest-based addons (cometvisu and rest):
ERROR o.a.cpr.AtmosphereFramework[:2306] - java.lang.AssertionError: Not a File: \org\atmosphere\annotation

As the required libraries are included I don´t know how to solve this and it seems to have no impact on the functionality.

[kaikreuzer]

ERROR o.a.cpr.AtmosphereFramework[:2306] - java.lang.AssertionError: Not a File: \org\atmosphere\annotation

As the required libraries are included I don´t know how to solve this and it seems to have no impact on the functionality.

This is strange as I thought that assertions are not checked at runtime - they are normally disabled by default, see http://docs.oracle.com/javase/7/docs/technotes/guides/language/assert.html#enable-disable

Could you try to add the launch parameter "-da“ and see if the error disappears?

Regards,
Kai

[peuter]

The -da parameter does not help.
This is the complete stacktrace:

ERROR o.a.cpr.AtmosphereFramework[:2306] -
java.lang.AssertionError: Not a File: \org\atmosphere\annotation
at
org.atmosphere.util.annotation.AnnotationDetector.detect(AnnotationDetector.java:352)
at
org.atmosphere.cpr.DefaultAnnotationProcessor.scanForAnnotation(DefaultAnnotationProcessor.java:147)
at
org.atmosphere.cpr.DefaultAnnotationProcessor.configure(DefaultAnnotationProcessor.java:133)
at
org.atmosphere.cpr.AtmosphereFramework.autoConfigureService(AtmosphereFramework.java:2268)
at
org.atmosphere.cpr.AtmosphereFramework.init(AtmosphereFramework.java:707)
at
org.atmosphere.cpr.AtmosphereFramework.init(AtmosphereFramework.java:614)
at org.atmosphere.cpr.AtmosphereServlet.init(AtmosphereServlet.java:86)
at
org.eclipse.equinox.http.servlet.internal.ServletRegistration.init(ServletRegistration.java:49)
at
org.eclipse.equinox.http.servlet.internal.ProxyServlet.registerServlet(ProxyServlet.java:179)
at
org.eclipse.equinox.http.servlet.internal.HttpServiceImpl.registerServlet(HttpServiceImpl.java:66)
at org.openhab.io.cv.CVApplication.activate(CVApplication.java:142)

And the source code in AnnotationDetector is (lines 330-353):
try {
jarFile = toFile(((JarURLConnection)
url.openConnection()).getJarFileURL());
} catch (ClassCastException cce) {
try {
// Weblogic crap
String u = url.toExternalForm();
if (u.startsWith("zip:")) {
u = u.substring(4);
if (!u.startsWith("file:")) {
u = "file:" + u;
}
u = u.substring(0, u.indexOf("!"));
}
jarFile = toFile(new URL(u));
} catch (Exception ex) {
throw new AssertionError("Not a File: " +
url.toExternalForm());
}
}
if (jarFile.isFile()) {
files.add(jarFile);
if (DEBUG) print("Add jar file: '%s'", jarFile);
} else {
throw new AssertionError("Not a File: " + jarFile);
}

Regards,
Tobias

Am 29.03.2014 18:27, schrieb kaikreuzer:

ERROR o.a.cpr.AtmosphereFramework[:2306] - java.lang.AssertionError:
Not a File: \org\atmosphere\annotation

As the required libraries are included I don´t know how to solve
this and it seems to have no impact on the functionality.

This is strange as I thought that assertions are not checked at
runtime - they are normally disabled by default, see
http://docs.oracle.com/javase/7/docs/technotes/guides/language/assert.html#enable-disable

Could you try to add the launch parameter "-da“ and see if the error
disappears?

Regards,
Kai

—
Reply to this email directly or view it on GitHub
#765 (comment).

[kaikreuzer]

Probably best to ask for help in the Atmosphere support list?

Am 29.03.2014 um 18:48 schrieb peuter [email protected]:

The -da parameter does not help.
This is the complete stacktrace:

ERROR o.a.cpr.AtmosphereFramework[:2306] -
java.lang.AssertionError: Not a File: \org\atmosphere\annotation
at
org.atmosphere.util.annotation.AnnotationDetector.detect(AnnotationDetector.java:352)
at
org.atmosphere.cpr.DefaultAnnotationProcessor.scanForAnnotation(DefaultAnnotationProcessor.java:147)
at
org.atmosphere.cpr.DefaultAnnotationProcessor.configure(DefaultAnnotationProcessor.java:133)
at
org.atmosphere.cpr.AtmosphereFramework.autoConfigureService(AtmosphereFramework.java:2268)
at
org.atmosphere.cpr.AtmosphereFramework.init(AtmosphereFramework.java:707)
at
org.atmosphere.cpr.AtmosphereFramework.init(AtmosphereFramework.java:614)
at org.atmosphere.cpr.AtmosphereServlet.init(AtmosphereServlet.java:86)
at
org.eclipse.equinox.http.servlet.internal.ServletRegistration.init(ServletRegistration.java:49)
at
org.eclipse.equinox.http.servlet.internal.ProxyServlet.registerServlet(ProxyServlet.java:179)
at
org.eclipse.equinox.http.servlet.internal.HttpServiceImpl.registerServlet(HttpServiceImpl.java:66)
at org.openhab.io.cv.CVApplication.activate(CVApplication.java:142)

And the source code in AnnotationDetector is (lines 330-353):
try {
jarFile = toFile(((JarURLConnection)
url.openConnection()).getJarFileURL());
} catch (ClassCastException cce) {
try {
// Weblogic crap
String u = url.toExternalForm();
if (u.startsWith("zip:")) {
u = u.substring(4);
if (!u.startsWith("file:")) {
u = "file:" + u;
}
u = u.substring(0, u.indexOf("!"));
}
jarFile = toFile(new URL(u));
} catch (Exception ex) {
throw new AssertionError("Not a File: " +
url.toExternalForm());
}
}
if (jarFile.isFile()) {
files.add(jarFile);
if (DEBUG) print("Add jar file: '%s'", jarFile);
} else {
throw new AssertionError("Not a File: " + jarFile);
}

Regards,
Tobias

Am 29.03.2014 18:27, schrieb kaikreuzer:

ERROR o.a.cpr.AtmosphereFramework[:2306] - java.lang.AssertionError:
Not a File: \org\atmosphere\annotation

As the required libraries are included I don´t know how to solve
this and it seems to have no impact on the functionality.

This is strange as I thought that assertions are not checked at
runtime - they are normally disabled by default, see
http://docs.oracle.com/javase/7/docs/technotes/guides/language/assert.html#enable-disable

Could you try to add the launch parameter "-da“ and see if the error
disappears?

Regards,
Kai

—
Reply to this email directly or view it on GitHub
#765 (comment).

—
Reply to this email directly or view it on GitHub.

[peuter]

It seems if someone did that already:
https://groups.google.com/forum/#!topic/atmosphere-framework/Yo4E_gXkZv4

And an issue is filed for this problem too:
Atmosphere/atmosphere#1539

Am 29.03.2014 18:54, schrieb kaikreuzer:

Probably best to ask for help in the Atmosphere support list?

Am 29.03.2014 um 18:48 schrieb peuter [email protected]:

The -da parameter does not help.
This is the complete stacktrace:

ERROR o.a.cpr.AtmosphereFramework[:2306] -
java.lang.AssertionError: Not a File: \org\atmosphere\annotation
at

org.atmosphere.util.annotation.AnnotationDetector.detect(AnnotationDetector.java:352)

at

org.atmosphere.cpr.DefaultAnnotationProcessor.scanForAnnotation(DefaultAnnotationProcessor.java:147)

at

org.atmosphere.cpr.DefaultAnnotationProcessor.configure(DefaultAnnotationProcessor.java:133)

at

org.atmosphere.cpr.AtmosphereFramework.autoConfigureService(AtmosphereFramework.java:2268)

at

org.atmosphere.cpr.AtmosphereFramework.init(AtmosphereFramework.java:707)
at

org.atmosphere.cpr.AtmosphereFramework.init(AtmosphereFramework.java:614)
at org.atmosphere.cpr.AtmosphereServlet.init(AtmosphereServlet.java:86)
at

org.eclipse.equinox.http.servlet.internal.ServletRegistration.init(ServletRegistration.java:49)

at

org.eclipse.equinox.http.servlet.internal.ProxyServlet.registerServlet(ProxyServlet.java:179)

at

org.eclipse.equinox.http.servlet.internal.HttpServiceImpl.registerServlet(HttpServiceImpl.java:66)

at org.openhab.io.cv.CVApplication.activate(CVApplication.java:142)

And the source code in AnnotationDetector is (lines 330-353):
try {
jarFile = toFile(((JarURLConnection)
url.openConnection()).getJarFileURL());
} catch (ClassCastException cce) {
try {
// Weblogic crap
String u = url.toExternalForm();
if (u.startsWith("zip:")) {
u = u.substring(4);
if (!u.startsWith("file:")) {
u = "file:" + u;
}
u = u.substring(0, u.indexOf("!"));
}
jarFile = toFile(new URL(u));
} catch (Exception ex) {
throw new AssertionError("Not a File: " +
url.toExternalForm());
}
}
if (jarFile.isFile()) {
files.add(jarFile);
if (DEBUG) print("Add jar file: '%s'", jarFile);
} else {
throw new AssertionError("Not a File: " + jarFile);
}

Regards,
Tobias

Am 29.03.2014 18:27, schrieb kaikreuzer:

ERROR o.a.cpr.AtmosphereFramework[:2306] -
java.lang.AssertionError:
Not a File: \org\atmosphere\annotation

As the required libraries are included I don´t know how to solve
this and it seems to have no impact on the functionality.

This is strange as I thought that assertions are not checked at
runtime - they are normally disabled by default, see

http://docs.oracle.com/javase/7/docs/technotes/guides/language/assert.html#enable-disable

Could you try to add the launch parameter "-da“ and see if the error
disappears?

Regards,
Kai

—
Reply to this email directly or view it on GitHub

#765 (comment).

—
Reply to this email directly or view it on GitHub.

—
Reply to this email directly or view it on GitHub
#765 (comment).

[teichsta]

Hi @digitaldan, any news on your post (mentioned in #1126) in the atmosphere forum? Could you please refer to your thread there? Best, Thomas E.-E.

[teichsta]

at all … we seem to still have the problem with this issue. Can anybody of the Atmosphere specialist (@digitaldan @oliver-M) please help out? Since i am currently preparing a 1.6.2 Bugfix Release it would be REALLY great to have a solution for this critical issue.

Any help is greatly appreciated!

Best, Thomas E.-E.

/cc @jochenkluger

[jochenkluger]

Hi,
I am getting this error on two testing Systems with openHAB 1.6.1 with greenT and with a custom atmosphere Client implementation.
If some testing or log is needed, I can provide it.
Jochen

[dominicdesu]

Hi,

the o.o.i.r.i.f.SendPageUpdateFilter[:91]- null error is caused by a NullPointerException in SendPageUpdateFilter.isPageUpdated() as this cannot work:

CacheEntry entry = ResourceStateChangeListener.getCachedEntries().get(clientId);
if(entry ==null || entry.getData() instanceof PageBean){
Object firedEntity = entry.getData();

I assume this should be entry != null && entry.getData() ... instead, but I guess it's better if @digitaldan has a look, too.

[dominicdesu]

And if somebody make a pull request, would be nice to add the stacktrace to the logger output, i.e. logger.error(e.getMessage(), e); instead of logger.error(e.getMessage());. Then the log file would have been more revealing :)

[digitaldan]

@dominicdesu , sorry that was my error, I added that null check to prevent the message, although its still acting the same as it did before. I'll fix that now, but while that error message may be related to this issue, its not the cause, so I don't think avoiding it will solve anything.
@teichsta I'll see if I can look at this again this weekend with a set of fresh eyes.

[teichsta]

thanks, that would be really great!

[teichsta]

@digitaldan another weekend approaching … hopefully with fresh eyes ;-)

Thanks, Thomas E.-E.

[digitaldan]

Yes, I'm looking at it again ;-) The heap dumps were very useful, thanks
for that.

On Fri, Jan 16, 2015 at 3:06 PM, Thomas Eichstädt-Engelen <
[email protected]> wrote:

@digitaldan https://github.com/digitaldan another weekend approaching …
hopefully with fresh eyes ;-)

Thanks, Thomas E.-E.

—
Reply to this email directly or view it on GitHub
#765 (comment).

[teichsta]

thanks @digitaldan … i am a bit unsure whether to wait for this for 1.6.2. Any clue what the solution will look like? Any suggestions timing wise?

[digitaldan]

I don't, it's tough, I run 4 android clients connected all the time as
touch screens with a fairly good size openHAB setup and do not see these
issues, there's probably a short term bandaid to aggressively clean up
stale broadcasters, long term may be OH 2.0 and something else ;-)

On Mon, Jan 19, 2015 at 6:29 AM, Thomas Eichstädt-Engelen <
[email protected]> wrote:

thanks @digitaldan https://github.com/digitaldan … i am a bit unsure
whether to wait for this for 1.6.2. Any clue what the solution will look
like? Any suggestions timing wise?

—
Reply to this email directly or view it on GitHub
#765 (comment).

[jochenkluger]

Hi,

if it helps, I could provide a Windows app that reproduces this behaviour in every setup I tested or I could provider the JavaScript code that is used behind the Client.

Or is there anything else I can do to help?

Jochen

---

Von: Dan [email protected]
Gesendet: Montag, 19. Januar 2015 15:31
An: openhab/openhab
Cc: Jochen Kluger
Betreff: Re: [openhab] Losing events on REST API (atmosphere) (#765)

I don't, it's tough, I run 4 android clients connected all the time as
touch screens with a fairly good size openHAB setup and do not see these
issues, there's probably a short term bandaid to aggressively clean up
stale broadcasters, long term may be OH 2.0 and something else ;-)

On Mon, Jan 19, 2015 at 6:29 AM, Thomas Eichstädt-Engelen <
[email protected]> wrote:

thanks @digitaldan https://github.com/digitaldan ... i am a bit unsure
whether to wait for this for 1.6.2. Any clue what the solution will look
like? Any suggestions timing wise?

Reply to this email directly or view it on GitHub
#765 (comment).

Reply to this email directly or view it on GitHubhttps://github.com//issues/765#issuecomment-70500870.

[gregeva]

@digitaldan - I am currently seeing this on my relatively simple OpenHAB 1.5.1 setup. No more than 50 items, 1 minute logging using RRD, charting using default charting engine, a few rules... running on Raspberry Pi B+. If you want to poke around, or get some logs, I would be happy to assist getting this nasty bug squashed.

[sja]

Hi!

I don't see any good or minimal solution here. The best solution in my eyes would be to write an own BroadcasterCache, like the UUIDBroadcasterCache. That can can save the sent messages not just in a list but in something like a ring buffer.

For old clients, everything works like before. Clients, which reconnect with a header "X-my-last-msg-id" will be handled in a new way: They'll get the lose message because now the server now have the information, where the clients is and what he missed. The limit of this method is the size of the ring buffer. I would suggest, we use a default size of 32 messages. That should be enough for small reconnects.

If the client says, 'my last messages was nr. 1' and the oldest message in the buffer has id 100, we have to answer something like 'reload everything'. That should be solved with the status code like 416 or just 400.

Does that make sense? Is that change possible to implement for iOS and Android? I'm just a web guy. :-)

[Testato]

Is this bug present on OH 1.7.0 too ?

[renatoriolino]

I think so. At least I have naver had those errors anymore.

[]'s

2015-07-16 13:36 GMT-03:00 Testato [email protected]:

Is this bug present on OH 1.7.0 too ?

—
Reply to this email directly or view it on GitHub
#765 (comment).

[teichsta]

since no real solution could be found over the past months i tend to leave this issue open and wait for the new OH2 to come (which removes Atmosphere completely). Any other suggestions?

[steve-bate]

@teichsta Does this mean we should label this issue as wont-fix?

[oliver-M]

I have some spare time next week. Maybe I can spent some time to find a
solution for this issue.

regards
Oliver
Am 20.11.2015 12:32 schrieb "Steve Bate" [email protected]:

@teichsta https://github.com/teichsta Does this mean we should label
this issue as wont-fix?

—
Reply to this email directly or view it on GitHub
#765 (comment).

[teichsta]

any news @oliver-M? If not i would tend indeed to close this issue as wont-fix

[teichsta]

as explained above … since the expertise for atmosphere is very rare we shouldn't too much efforts anymore. Thanks to all participating, discussing, helping on this issue!

[paulianttila]

Maybe wiki could contain "known issues" where this kind of behaviors are documented