Two different formats for one and the same event

Hi,
I have here a very strange effect. I am new to Spark and the cloud stuff and I am experimenting with events. My partner set up a simple trigger, which fires every 10 seconds and sends alternately true and false. So far so good. I register to this event and get:

"10\r\nevent: Movement\n70\r\ndata: {"data":"true","ttl":"60","published_at":"2015-04-09T19:30:55.535Z","coreid":"xxxxxxxxxxxxxxxxxxxxxxx"}"

Fine. Easily to parse. No problem... if only this were the only format. Once in a while I get:

"80\r\nevent: Movement\ndata: {"data":"true","ttl":"60","published_at":"2015-04-09T19:31:15.533Z","coreid":"xxxxxxxxxxxxxxxxxxxxxxxx"}"

Again, not problem to parse... The question is: Why? Why do I have to anticipate two different event formats? The second form roughly seems to arrive randomly.

Okay,

Just a wild guess: Is it possible that the event:Movement sometimes does not send the amount off movement? Resulting in an empty part ā€˜70ā€™ ?

I donā€™t know. Hard for me to test. My partner with his spark sits in Norway, I on the other hand sit in Germany. :smile:
But is such a bug even possible? Why should something like that happen randomly? And the missing 70 in front of the data is added to the event name at the beginning of the line. Apart from that everything looks normalā€¦ timestamps, device ids.

Well @tanuki
I live in Sweden :wink: So I am the man in the middle. Can you share the code ? copy and paste it in the reply, then apply formatting as is explained in this post.
Ask your Norwegian friend to do the same, than we can have a look at it.

Thank you. But not today. Hi is a bit sick. :mask:

Hi @tanuki

If you are getting this from a subscribed core over the serial port, I think it is very likely there is some other Serial.print statement that is messing things up, like in an interrupt handler etc.

You should also check your terminal program (again assuming serial data from a core) to see if it is changing the line terminating characters. Usually there are settings for this.

I can see your Movement events in the public event stream and I logged them using curl. The published data on the web interface only has 0x0a linefeed characters (\n) and never has any 0x0d (\r) characters. I suspect very strongly that a core subscribing to these events would not get any 0x0d (\r) characters either.

I will pass this to my partner. He has access to the hardware. I am the high-level guy on the other end of the cloud. At the moment I just added a second regexp rule. Dirty, but works for now :slight_smile:

So you are reading this from the cloud with your own program, something is wrong with your program. When I log these events using curl I do not see any of the problem you are having.

Strange. I see it in the raw, unchanged data I get directly out of the socket. Usually I am extremely careful with 'impossible', but in this case? Bugs in my code might skip an event, i.e. my regexp is false and certain lines get dropped since they don't match. But here a bug would have to rewrite a line. Taking the 70 from data and add it to the 10 of the event name.

10\r\nevent: Movement\n70\r\ndata: {\

to

80\r\nevent: Movement\ndata:

This is no simple corruption due to data loss. I would have to invest actual work if I wanted this effect.

My advice is to try it with curl and check the results.

Curl does not help here... at least not the way I use it. Is there a switch, which lets me see the raw data?

When I use:

curl -H "Authorization: Bearer <my access_token" https://api.spark.io/v1/devices//events/Movement

I get:

event: Movement
data: {"data":"false","ttl":"60","published_at":"2015-04-09T21:26:05.353Z","coreid":"51ff70065082554930061487"}

I don't see the linebreak chars or any indices. Both forms probably look identical in curl.

Ok.... More info. I used curl and dumped the binary data with --trace into a file. There I was able to see exactly the same effect. So it is not only my program, but also curl. I think now we can rule out the problem on my side? :innocent:

Try the --verbose flag to curl.

I think I see what your problem is: the Transfer-Encoding is chunked so you are getting the chunk sizes periodically.

Does your program handle chunked HTTP connections?

Yes, it handles chunked HTTP connections. As I wrote aboveā€¦ I now see exactly the same when I use curl and look at the raw data.

Hi @tanuki

OK so curl and Javascript and Chrome and lots of other things work fine with this stream and donā€™t have these problems in its output, so there is something curl is doing that your program is not doing and you have to figure out what that is.

You understand that the chunk sizes are sent in the stream periodically, right?

I know chunked transfers. :smile:
And now with my workaround my program does not have problems either. The question is and was: Why do I need this workaround? For me it looks like there are two different, but valid types of protocols mixed in the stream. There isnā€™t just now and then a chunk size added to the stream. And if both types really are different, but valid protocol versions, it would not be surprising that curl, Javascript, or Chrome can handle them. It would only be surprising to have both versions in one and the same stream.

Ok, I think I found the problemā€¦
Looks like I get now an then some stuff, which I did not expect. This really did corrupt my chunk handling.

1 Like

The 10 and 70 and the 80 are the chunk sizes in ASCII hex and are correct for the data being sent.

If you are asking why the chunk sizes are different rather than always being 80 or 81, I think the answer is that encoding host is free to use whatever chunk size they want and the receiver has to deal with it.

Yep, I 'tailored' my code too close to the movement events. And yes, I got something wrong... not the initial chunk sizes, but the terminating chunk. I thought it must be 0, but in this stream it is 1.

0000: 31 0d 0a 0a 0d 0a 1.....

This botched my algorithm a bit.
Adjusted... now I don't need my workaround anymore.
Thanks for your help. :smile:

Hmm... little addendum... I am googeling now for quite a while about the last chunk.
According to HTTP/1.1: Protocol Parameters 3.6.1 Chunked Transfer Coding the last chunk must be:

last-chunk = 1*("0") [ chunk-extension ] CRLF

I was looking if I find something about "1*("1") [ chunk-extension ] CRLF", which caused my problems (this and my organisational blindness), but nothing. Do I still overlook something? Curl, Javascript, or Chrome don't seem to have problems with this wrong (?) last chunk.

In theory this stream never closes and sends ā€œkeep alivesā€ so there is not a real last chunk.

I donā€™t know how the ā€œkeep alivesā€ are sent, they show up as CRLF in the browser. Maybe @Dave knows if they are sent with a chunk size 1.

1 Like

Last mystery solved.

From:

Note: The comment line can be used to prevent connections from timing out; a server can send a comment periodically to keep the connection alive.

But:

Note: If a line doesn't contain a colon, the entire line is treated as the field name, with an empty value string.

And empty value strings are ignored, effectively can be used as another way to keep a connection alive.

So, bko, you were right with 'keep alives'.

2 Likes