Subscription request being sent twice

[zeekhuge]

Issue Description

I am using LiveQuery with Android device. The problem is that the events (like UPDATE) were delivered twice when they should have been delivered only once. I tried to look in here,
but couldnt really see a problem. Then I enabled logLevel : verbose in the server and the server actually receives the request twice. Am I doing something wrong ? or is it really a bug ?

Steps to reproduce

The server config should contain these keys :

    "liveQuery" : {
        "classNames":["LiveQueryTest"]
    },
    "startLiveQueryServer" : true

The android client has this code :

		final ParseLiveQueryClient lq = ParseLiveQueryClient.Factory.getClient();
		lq.registerListener(new ParseLiveQueryClientCallbacks() {
			@Override
			public void onLiveQueryClientConnected (ParseLiveQueryClient client) {
				ParseQuery<ParseObject> pq = new ParseQuery<>("LiveQueryTest");
				pq.whereEqualTo("objectId","PVF6o0rLVM");
				SubscriptionHandling<ParseObject> sh = lq.subscribe(pq);
				sh.handleEvents(new SubscriptionHandling.HandleEventsCallback<ParseObject>() {
					@Override
					public void onEvents (ParseQuery<ParseObject> query, SubscriptionHandling.Event event, ParseObject object) {
						Log.d(TAG, "Received subscription event : " + event + "\n current object state : " + object.toString());
					}
				});
			}

			@Override
			public void onLiveQueryClientDisconnected (ParseLiveQueryClient client, boolean userInitiated) {

			}

			@Override
			public void onLiveQueryError (ParseLiveQueryClient client, LiveQueryException reason) {

			}

			@Override
			public void onSocketError (ParseLiveQueryClient client, Throwable reason) {

			}
		});
		lq.connectIfNeeded();

Logs/Trace

Logs on android client :

V/ParseLiveQueryClient: Socket stateChanged
V/ParseLiveQueryClient: Socket opened
D/ParseLiveQueryClient: Sending over websocket: {"op":"connect","applicationId":"*************","sessionToken":"**********************************"}
                                                                       
                                                                       [ 09-19 11:43:15.451   363:  363 D/         ]
                                                                       HostConnection::get() New Host Connection established 0xaa92b680, tid 363
V/ParseLiveQueryClient: Socket onMessage {"op":"connected","clientId":0}
D/ParseLiveQueryClient: Sending over websocket: {"op":"subscribe","requestId":1,"sessionToken":"**********************************","query":{"className":"LiveQueryTest","where":{"objectId":"PVF6o0rLVM"}}}
V/ParseLiveQueryClient: Connected, sending pending subscription
D/ParseLiveQueryClient: Sending over websocket: {"op":"subscribe","requestId":1,"sessionToken":"**********************************","query":{"className":"LiveQueryTest","where":{"objectId":"PVF6o0rLVM"}}}
V/ParseLiveQueryClient: Socket onMessage {"op":"subscribed","clientId":0,"requestId":1}
V/ParseLiveQueryClient: Socket onMessage {"op":"subscribed","clientId":0,"requestId":1}

Logs on the server :

verbose: Request: {"op":"connect","applicationId":"*****appId*****","sessionToken":"*****sessionToken*****"}
info: Create new client: 0
verbose: Push Response : "{\"op\":\"connected\",\"clientId\":0}"
verbose: Request: {"op":"subscribe","requestId":1,"sessionToken":"*****sessionToken*****","query":{"className":"LiveQueryTest","where":{"objectId":"PVF6o0rLVM"}}}
verbose: Push Response : "{\"op\":\"subscribed\",\"clientId\":0,\"requestId\":1}"
verbose: Create client 0 new subscription: 1
verbose: Current client number: 1
verbose: Request: {"op":"subscribe","requestId":1,"sessionToken":"*****sessionToken*****","query":{"className":"LiveQueryTest","where":{"objectId":"PVF6o0rLVM"}}}
verbose: Push Response : "{\"op\":\"subscribed\",\"clientId\":0,\"requestId\":1}"
verbose: Create client 0 new subscription: 1
verbose: Current client number: 1
verbose: REQUEST for [POST] /test/classes/_Installation: {
  "GCMSenderId": "987703271850"
} method=POST, url=/test/classes/_Installation, x-parse-session-token=*****sessionToken*****, x-parse-application-id=*****appId*****, x-parse-client-version=a1.15.7, x-parse-app-bu
ild-version=1, x-parse-app-display-version=1.0, x-parse-os-version=6.0, user-agent=Parse Android SDK 1.15.7 (me.zeekhuge.app/1) API Level 23, x-parse-installation-id=963e1e55-91e3-4b6c-b
d74-be1362141187, x-parse-client-key=, content-type=application/json, content-length=30, host=10.0.2.2:1337, connection=Keep-Alive, accept-encoding=gzip, GCMSenderId=987703271850
verbose: RESPONSE from [POST] /test/classes/_Installation: {
  "response": {
    "updatedAt": "2017-09-19T07:14:20.935Z"
  }
} updatedAt=2017-09-19T07:14:20.935Z
verbose: REQUEST for [PUT] /test/classes/LiveQueryTest/PVF6o0rLVM: {
  "state": 2
} method=PUT, url=/test/classes/LiveQueryTest/PVF6o0rLVM, host=localhost:1337, connection=keep-alive, content-length=174, origin=http://localhost:4040, user-agent=Mozilla/5.0 (X11; Linux x86
_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.113 Safari/537.36, content-type=text/plain, accept=*/*, dnt=1, referer=http://localhost:4040/apps/test%20-%20app/browser/LiveQuer
yTest, accept-encoding=gzip, deflate, br, accept-language=en-US,en;q=0.8,hi;q=0.6, state=2
verbose: Raw request from cloud code current : {"state":2,"createdAt":"2017-09-19T07:01:14.800Z","updatedAt":"2017-09-19T07:15:23.712Z","objectId":"PVF6o0rLVM"} | original : {"state":1,"crea
tedAt":"2017-09-19T07:01:14.800Z","updatedAt":"2017-09-19T07:01:14.800Z","objectId":"PVF6o0rLVM"}
verbose: Subscribe messsage "{\"currentParseObject\":{\"state\":2,\"createdAt\":\"2017-09-19T07:01:14.800Z\",\"updatedAt\":\"2017-09-19T07:15:23.712Z\",\"objectId\":\"PVF6o0rLVM\",\"__type\"
:\"Object\",\"className\":\"LiveQueryTest\"},\"originalParseObject\":{\"state\":1,\"createdAt\":\"2017-09-19T07:01:14.800Z\",\"updatedAt\":\"2017-09-19T07:01:14.800Z\",\"objectId\":\"PVF6o0r
LVM\",\"__type\":\"Object\",\"className\":\"LiveQueryTest\"}}"
verbose: *****appId*****afterSave is triggered
verbose: ClassName: LiveQueryTest | ObjectId: undefined
verbose: Current client number : 1
verbose: RESPONSE from [PUT] /test/classes/LiveQueryTest/PVF6o0rLVM: {
  "response": {
    "updatedAt": "2017-09-19T07:15:23.712Z"
  }
} updatedAt=2017-09-19T07:15:23.712Z
verbose: Original {"state":1,"createdAt":"2017-09-19T07:01:14.800Z","updatedAt":"2017-09-19T07:01:14.800Z","__type":"Object","className":"LiveQueryTest","objectId":"PVF6o0rLVM"} | Current {"
state":2,"createdAt":"2017-09-19T07:01:14.800Z","updatedAt":"2017-09-19T07:15:23.712Z","__type":"Object","className":"LiveQueryTest","objectId":"PVF6o0rLVM"} | Match: true, true, true, true
| Query: LiveQueryTest:objectId|["PVF6o0rLVM"]
verbose: Push Response : "{\"op\":\"update\",\"clientId\":0,\"requestId\":1,\"object\":{\"state\":2,\"createdAt\":\"2017-09-19T07:01:14.800Z\",\"updatedAt\":\"2017-09-19T07:15:23.712Z\",\"__
type\":\"Object\",\"className\":\"LiveQueryTest\",\"objectId\":\"PVF6o0rLVM\"}}"
verbose: Original {"state":1,"createdAt":"2017-09-19T07:01:14.800Z","updatedAt":"2017-09-19T07:01:14.800Z","__type":"Object","className":"LiveQueryTest","objectId":"PVF6o0rLVM"} | Current {"
state":2,"createdAt":"2017-09-19T07:01:14.800Z","updatedAt":"2017-09-19T07:15:23.712Z","__type":"Object","className":"LiveQueryTest","objectId":"PVF6o0rLVM"} | Match: true, true, true, true
| Query: LiveQueryTest:objectId|["PVF6o0rLVM"]
verbose: Push Response : "{\"op\":\"update\",\"clientId\":0,\"requestId\":1,\"object\":{\"state\":2,\"createdAt\":\"2017-09-19T07:01:14.800Z\",\"updatedAt\":\"2017-09-19T07:15:23.712Z\",\"__
type\":\"Object\",\"className\":\"LiveQueryTest\",\"objectId\":\"PVF6o0rLVM\"}}"

Expected Results

The server should recieve only one subscription request and hence should dispatch the UPDATE events only once.

Actual Outcome

As it can be seen in the logs that the server is recieving 2 subscription request and hence dispatches the UPDATE events twice.

Environment Setup

• Server
  • parse-server version (Be specific! Don't say 'latest'.) : 2.5.3
• Client
  • client name : Android
  • client version : 1.0.4

[zeekhuge]

Okay, so I think I found the problem.
So, If I subscribe() inside the onLiveQueryClientConnected() its sending the subscription request twice. If I subscribe() outside that callback, It works fine.

I thought one could only subscribe when the LiveQueryClient is connected.

Though not a big issue, it still looks like a bug.