Is Ionic sending multiple requests?

[ioclaudio]

Hi,
in an Ionic4 app I’m calling a web service “rental” in this way:

this.wsManager.startTrip(data)
	.subscribe(data => {
	....
    }
		

Where startTrip is:

startTrip(data) {
	...
return this.httpClient.post(wsUrl, commandBody,{headers: commandHeaders});

}

If the web service is slow it seems that the request is sent two times:

I can see this also in the log of the web service.

Why is Ionic calling the web service twice?
Is it possible to disable this behaviour?

Thank you very much

claudio

[richardshergold]

is the first request the pre-flight request?

[ioclaudio]

yes, I think so.
The method " this.httpClient.post" I can see is called once.
Probably the web services doesn’t manage the OPTIONS request in the right way, I don’t know.
The web service, however, runs twice.

cld

[ioclaudio]

The fact is that the backend method is called two times only if it is slow (I put a delay to simulate this).
Without the delay the web service is called once, so I suppose that probably is the httpClient library that makes two calls.

cld

[alexmigwi]

If you examine the request header on the developer tools you should be able to see which http verb was invoked when the call was made. When you are making cross-site calls you will often see a pre-flight request before the actual request.

to quote developer.mozilla.org

A CORS preflight request is a CORS request that checks to see if the CORS protocol is understood and a server is aware using specific methods and headers.

It is an OPTIONS request, using three HTTP request headers: Access-Control-Request-Method , Access-Control-Request-Headers , and the Origin header.

A preflight request is automatically issued by a browser and in normal cases, front-end developers don’t need to craft such requests themselves. It appears when request is qualified as “to be preflighted” and omitted for simple requests.

For example, a client might be asking a server if it would allow a DELETE request, before sending a DELETE request, by using a preflight reques.
Cross-site requests are preflighted like this since they may have implications to user data.

[rapropos]

@ioclaudio

Probably the web services doesn’t manage the OPTIONS request in the right way, I don’t know.

This would be fairly weird.

@ioclaudio

The web service, however, runs twice.

Can you elaborate a bit about precisely what you mean here and what evidence you’re relying on? For example, are you looking at server-side logs from an httpd like apache or nginx, at logs from a middleware app sitting behind httpd, at wireshark or something on your local network?

I don’t believe HttpClient silently retries requests. One cause of this that I have personally been bitten by before is when you subscribe multiple times to the same Observable coming back from HttpClient, so maybe you could audit your code for that possibility.

[ioclaudio]

@rapropos

Can you elaborate a bit about precisely what you mean here and what evidence you’re relying on?

I have a web service that waits for an external event to respond.
When this external event occurs after a long time, I can see, from the log of the server, that the web service is called again (only in this case).

If I call the web service with Postman this doesn’t happen.
However the logs of the app say that the post of the httpClient is called once.

These are the server logs

With Ionic:

INFO::NEW RENTAL
INFO::ACK NOT RECEIVED --> Attempt: 0 
INFO::NEW RENTAL
INFO::ACK NOT RECEIVED --> Attempt: 1 
INFO::ACK NOT RECEIVED --> Attempt: 0 
INFO::ACK NOT RECEIVED --> Attempt: 2 
INFO::RENTAL NOT STARTED
INFO::ACK NOT RECEIVED --> Attempt: 1

With Postman:

``
INFO::NEW RENTAL
INFO::ACK NOT RECEIVED → Attempt: 0
INFO::ACK NOT RECEIVED → Attempt: 1
INFO::ACK NOT RECEIVED → Attempt: 2
INFO::RENTAL NOT STARTED

So I think that is httpClient that makes two calls. 
Is it perhaps due to some timeout?


Claudio

[rapropos]

@ioclaudio

I have a web service that waits for an external event to respond.

For the sake of explication, let’s say there are three distinct machines here. A is running your Ionic app. B runs an httpd. C runs a mysterious program.

A talks only to B. B can talk to both A and C.

Are you saying that you have the following workflow?

The Ionic app on A makes a request to B. B forwards that request to C. C then waits for an external act of god. When act of god happens, C responds to B, and B then repackages that response and responds in turn to A?

If that’s correct so far, can the bug be described as follows?

Ionic app makes request to B. At some point before the response back from B to A (and maybe even before C has said anything to B), A then sends, unsolicited, a second identical request to B?

If that’s the situation, I don’t see anything in here, which I believe to be the relevant Angular code, that would initiate that second request. So I would again look for possibilities in your app code that makes a second request or subscribes multiple times to the Observable resulting from the first one. Especially check any interceptors you have.

So I think that is httpClient that makes two calls. Is it perhaps due to some timeout?

There is a comment starting at line 237 of the above link that specifically says that connection timeouts (and other lower-level network abnormalities) are simply reported as errors back from HttpClient.

[ioclaudio]

@rapropos

Ionic app makes request to B. At some point before the response back from B to A (and maybe even before C has said anything to B), A then sends, unsolicited, a second identical request to B?

Yes, this is what happens when I call B using the app (web o real device).
If I call B with Postman, there isn’t a second call because Postman has a timout and generates an error.
This should be the right behaviour according to me.

If HttpClient generates an error when a timeout occurs, then I agree with you it should be something related to the Observable.

This is the code I’m using to make the request from A to B:

Start on the page:

  console.log('START-startRentalTrip:', startRentalTrip);
  this.rentalManager.startRental(startRentalTrip)
	.then(data => {
	  console.log('START-data:', data);
	  ....
	}, (err: HttpErrorResponse) => {
		.....
	});

Start on the controller:

  async startRental(startRentalTrip): Promise<any> {
    const deviceId =  startRentalTrip.deviceId;
	console.log('@@@ startRental-SUBSCRIBE create Promise:');
    return new Promise ((resolve, reject) => {
      console.log('@@@ startRental-SUBSCRIBE request:');
      this.wsManager.startRental(startRentalTrip)
        .subscribe(data => {
          console.log('@@@ startRental-SUBSCRIBE result:', data);
		  .......
          resolve(this.device_status);
        }, err => {
          console.log('ERR-START:', err);
          reject(err);
        });
    });
  }

Call of the REST api:

  startRental(startRentalTrip) {
	.....
    console.log('@@@POST REQUEST@@@');
    return this.httpClient.post(stopRentalUrl,
      commandBody,
      {headers: this.getWsHeader(), responseType: responseType});
  }

It is a bit complictated, but the log show that is function is called once.
The log on Chrome is:

START-startRentalTrip: {deviceId: 77, ...}
@@@ startRental-SUBSCRIBE request:
@@@POST REQUEST @@@
ERR-START: HttpErrorResponse {headers: HttpHeaders, status: 0, statusText: "Unknown Error" ok: false, …}

it’s a real mystery.

cld

[rapropos]

I don’t know if it’s related, but the Promise you’re explicitly creating doesn’t need to exist and makes the code harder (for me at least) to follow. I’m also leery of the magical code that async/await creates under the surface, so if I were in your situation, I would get rid of that too (although I realize my opinion here may not be widely shared).

By any chance, are you using Angular proxy configuration?

[danieldugger]

Post the code that is responsible for generating the console logs that print the messages that are being returned but not shown within your code blocks above?

[ioclaudio]

@rapropos

By any chance, are you using Angular proxy configuration?

No, I’m not using it.

[ioclaudio]

@rapropos

I don’t know if it’s related, but the Promise you’re explicitly creating doesn’t need to exist and makes the code harder (for me at least) to follow . I’m also leery of the magical code that async/await creates under the surface, so if I were in your situation, I would get rid of that too (although I realize my opinion here may not be widely shared).

Yes, I think that I will refactor that code, however, the log shows that the POST call is invoked only once.

cld

[rapropos]

To get back to @richardshergold’s initial instinct, do we have confirmation from the server logs what the verb of each of these two requests is? Do we know if it’s POST / POST or potentially OPTIONS / POST?

[ioclaudio]

The first is the POST and the second the OPTIONS.
I don’t know why are inverted.
No other requests appear in Chrome.

This is the log after the timeout:

This is the log on the server:

TRIP::NEW TRIP - time: Wed Sep 02 2020 15:40:57 GMT+0200 (Central European Summer Time)
TRIP::ACK NOT RECEIVED --> Attempt: 0 
TRIP::ACK NOT RECEIVED --> Attempt: 1 
TRIP::NEW TRIP - time: Wed Sep 02 2020 15:42:57 GMT+0200 (Central European Summer Time)
TRIP::ACK NOT RECEIVED --> Attempt: 2 
TRIP::TRIP NOT STARTED 
TRIP::ACK NOT RECEIVED --> Attempt: 0 
TRIP::ACK NOT RECEIVED --> Attempt: 1 
TRIP::ACK NOT RECEIVED --> Attempt: 2 
TRIP::TRIP NOT STARTED 

Two request (NEW TRIP) on the server, but only one request from Ionic (apparently).
The server uses Node.js + Express.
Using Postman the problem doesn’t exist.

cld

[ioclaudio]

Little updates:

• This strange behaviour does NOT happen using Postman (sending the POST request directly to the server) or using the iOS app. It happens only with the Android app or via Web.

• Even removing the new Promise() as @rapropos suggested the problem persists.

I’ve simplified the code in this way:

return this.httpClient.post(urlMethod, commandBody, { headers: this.getWsHeader(), responseType: 'text'})
	.subscribe(data => {
		console.log('@@@ START-OK:', data);
	}, err => {
		console.log('@@@ START-ERROR:', err);
	});

No other calls.
The problem persists, so the problem relies definitely on the implementation of httpClient on Android.

cld

[rapropos]

@ioclaudio

The first is the POST and the second the OPTIONS.
I don’t know why are inverted.

That would seem to be unusual, but if they’re not both POSTs, I would not think that it’s HttpClient’s problem, because CORS stuff happens below its layer. Can you also add the verbs to the server logging, so we know (a) that one request is indeed an OPTIONS and one a POST as far as the server sees it, and (b) what order they come in (if consistent)?

[ioclaudio]

From the log of the server I can see that are arriving two POST to the web service.
The OPTIONS is managed correctly doesn’t arrive to the web service level.

[danieldugger]

Possibly an issue with build assets not being updated for iOS that is responsible for it still working and all other platforms not?

[ioclaudio]

The problem is present on Android and via Web, it is not present on iOS and calling the web services using Postman.

cld