Meteor Losing Message ID randomly, and also dropping a message

[Dave Dev]

Good Afternoon Everyone,
I've been using meteor for several months now with the deacon
client on Android. It mainly functions as an alternative to google
push notifications. In an effort to make the delivery a little more
robust, we do some limited tracking of message ID on the client side.
Mainly we use the header template from the meteor server to indicate
the last message on a specific channel. Unfortunately, we're seeing
some interesting behavior wrt message ID's.

At first everything behaves normally, and we get channel info with
last message IDs on every connect request But then after a long period
of no messages on that channel, it starts reporting the last message
ID as 0. And it's not until another message is sent through that
channel that it starts reporting the correct last message ID. Even
more strange, the actual message sent to correct the behavior doesn't
get delivered until several additional messages are sent through.

I wrote a simple curl loop that connects to the meteor server, then
when the connection is dropped it waits 2 seconds and reconnects. My
server is set up as per deacon and will drop any connection after 60
seconds. You can see initally the connect header gives the correct ID,
then only shows 0, then starts reporting the correct ID again:

* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
5384)
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
5384)
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
5384)
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
5384)
< m.p
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
0)
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
0)
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
0)
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
0)
< m.p
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
0)
< m.p
* Connection #0 to host ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com left
intact
* Closing connection #0
* About to connect() to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com port
80 (#0)
* Trying 107.11.22.33... connected
* Connected to ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
(107.11.22.33) port 80 (#0)
> GET /push/1234/longpoll/64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424 HTTP/1.1
> User-Agent: curl/7.21.4 (universal-apple-darwin11.0) libcurl/7.21.4 OpenSSL/0.9.8r zlib/1.2.5
> Host: ec2-XXX-XX-XXX-XX.compute-1.amazonaws.com
> Accept: */*
>
< HTTP/1.1 200 OK
<
Channel("64e66cf4db132c15e3920b8c42a20723fc26528ce037475a156e14776ec65424".
5643)
< m.p

[Dave Dev]

So it seems that I can reproduce this by clearing the channel cache:

killall -s SIGUSR1 meteord

Apparently it is clearing the channel cache after a certain amount of
time. Can someone comment on how to control that or what the expected
behavior is for this? Does it clear the cache for every channel after
a certain amount of time?

Thanks,
Dave