[TIMOB-6016] iOS: Http request sent twice on ios 5
GitHub Issue | n/a |
---|---|
Type | Bug |
Priority | High |
Status | Closed |
Resolution | Fixed |
Resolution Date | 2012-04-02T11:25:59.000+0000 |
Affected Version/s | Release 1.7.3 |
Fix Version/s | Release 1.8.0, Release 1.7.6 |
Components | iOS |
Labels | dr-list, module_network |
Reporter | Ryan DuVal |
Assignee | Stephen Tramer |
Created | 2011-11-04T12:57:14.000+0000 |
Updated | 2014-06-19T12:42:43.000+0000 |
Description
With reference to [http request sent twice on ios 5 and mobile sdk 1.7.3](http://developer.appcelerator.com/question/127415/http-request-sent-twice-on-ios-5-and-mobile-sdk-173), we are seeing this as well.
Below is an app.js that queries our development server which you can use to reproduce the issue. This works correctly on on iPad 2 running 4.3.5 and iPad 1 running 4.3.5, but duplicate requests are generated on iOS5. See attached screenshot.
var xhr = Ti.Network.createHTTPClient();
xhr.setTimeout(10000);
var win = Ti.UI.createWindow({
backgroundColor: "#fff",
height: "100%",
width: "100%"
}),
top = Ti.UI.createTextArea({
borderWidth: 1,
left: 0,
top: 0,
height: 300,
width: "100%",
value: ""
}),
bottom = Ti.UI.createTextArea({
borderWidth: 1,
left: 0,
bottom: 0,
height: 300,
width: "100%",
value: ""
}),
btn = Ti.UI.createButton({
height: 100,
width: 300,
right: 20,
title: "make call"
}),
stats = Ti.UI.createLabel({
left: 20,
height: 200,
width: "auto",
text: ""
}),
data = {
clicked: 0,
success: 0,
dupe: 0,
ratio: 0,
events: 0,
calls: 0
};
win.add(top);
win.add(stats);
win.add(btn);
win.add(bottom);
win.open();
function callback(data) {
var msg;
if (data.success) {
msg = "Success";
record("success", true);
} else if (!data.success && data.error && data.error == "duplicate request") {
msg = "Error: duplicate request";
record("dupe", true);
} else
msg = "Error: Unknown\ndata: " + JSON.stringify(data);
top.value += data.auth + ": " + msg + "\n";
}
Ti.App.addEventListener("events/detail", callback);
btn.addEventListener("click", function(e) {
bottom.value += "call()\n";
record("events");
record("clicked");
call("POST", "events/detail", {
eventId: 1,
longitude: -105.24097442626953,
latitude: 39.97970199584961,
appId: 1
});
});
function call(method, uri, data) {
Ti.API.info("Network ready state: " + xhr.readyState);
var base = "http://dev.mobilestudying.com:8080";
var _uri = "/examjam-1.0/" + uri;
var timestamp = new Date().getTime();
var contentType = "application/x-www-form-urlencoded";
var secret = "88627d4c72a611e09f3efb27cf9a9621";
var hash = [method, _uri.split("?", 1)[0], contentType, timestamp, secret];
var auth = Ti.Utils.md5HexDigest(hash.join("\n"));
xhr.onload = function() {
var data = this.responseText ? JSON.parse(this.responseText) : null;
data.auth = auth;
//Ti.API.info("data: " + JSON.stringify(data));
Ti.App.fireEvent(uri.split("?")[0], data);
};
xhr.onerror = function(){
Ti.API.debug("ERROR: Call failed to '" + uri + "': " + this.responseText);
Ti.API.debug("ERROR: data: " + JSON.stringify(this.responseData));
Ti.API.debug("ERROR: status code: " + this.status);
};
xhr.open(method, base + _uri);
xhr.setRequestHeader("Content-Type", contentType);
xhr.setRequestHeader("X-ExamJam-APIKey", "b95a0551553ae446fa39b95f8ffbac26");
xhr.setRequestHeader("Date", timestamp);
xhr.setRequestHeader("Authorization", auth);
bottom.value += "send()\n";
record("calls");
xhr.send(data);
}
function record(value, display) {
data[value]++;
if (display) {
stats.text = "Clicked (events/calls): " + data.clicked + " (" + data.events + "/" + data.calls + ")";
stats.text += "\nSuccess: " + data.success;
stats.text += "\nDupe (ratio): " + data.dupe + " (" + ((data.dupe / data.success) * 100) + "%)";
}
}
Attachments
File | Date | Size |
---|---|---|
app_screenshot.png | 2011-11-05T10:11:20.000+0000 | 126872 |
app.js | 2011-11-05T10:11:20.000+0000 | 3244 |
photo.PNG | 2011-11-04T12:57:14.000+0000 | 185874 |
Paul, moving this into Titanium Community as this is the best place to triage this. Can you please take a look at this ASAP?
I should add that this doesn't happen every single request, but if you click the button 5-10 times, you should see a few. Can also confirm this happens in 1.7.5 as well. Just had my manager run it (he has iOS 5) and he reported that "It started off with 5 straight Success actions, but now every other is a duplicate". Finally, we created a native iOS app with XCode that does exactly the same thing as the provided app and it didn't occur.
I reproduced this on an iPod Touch running iOS5. Can you determine if the whole call event listener is called twice, or just the HTTP call? This can help you determine if its a flaw with HTTPClient or with adding and removing Ti.App events. I think I may have spotted a potential error in the logic. Anytime you click the button, you add a Ti.App listener. The only time you clear if, however, is on a successful onload. If there is an error with your HTTP call, or anything that prevents the onload from firing, you'll end up with multiple instances of your Ti.App listener, resulting in duplicate calls. Try to change up your logic to either tighten up this flow, or move the Ti.App.addEventListener() call outside of the button click altogether, only adding it once.
Hi Ryan, thank you for bringing this bug to our attention. I have moved your issue to the TIMOB project now. Please note the changes that were necessary in order to make this possible, which are described in [How to Submit a Bug Report](http://wiki.appcelerator.org/display/guides/How+to+Submit+a+Bug+Report). This will avoid any delays for your tickets in future. In particular, note the [JIRA Ticket Checklist](http://wiki.appcelerator.org/display/guides/How+to+Submit+a+Bug+Report#HowtoSubmitaBugReport-JIRATicketChecklist). Please see [Projects Overview](http://wiki.appcelerator.org/display/guides/How+to+Submit+a+Bug+Report#HowtoSubmitaBugReport-ProjectsOverview) for the reason why tickets should be created in the TC project. Many thanks
This ticket is a duplicate of an issue we are currently in the process of resolving internally. Any commit which solves this other issue will be tagged for this one as well, and we will close it at the appropriate time. We will ensure validation against your provided test as well as the internal one.
I am continually receiving errors of this type from the test:
This is occurring on both iOS 4.3 and iOS 5.0.
As requested, the full request being sent over the wire that's generating this error:
NOTE: This failure occurs ONLY in 1.8.0. The difference between the headers appears to be the following:
The server merely needs to be modified to accept the
charset=utf-8
information.Fair enough, we can modify our authorization hash to include the charset. You have enough to go off of now?
Hi Stephen That was thoughtful of you, about the telephone no. Thank you for doing that! :) We are getting a number of similar reports of problems between xhr and iOS5. Would you mind looking at the following, and letting me know whether existing tickets cover the problems they describe, or whether we need fresh tickets? http://developer.appcelerator.com/question/127817/getting-an-401-error-on-xhr http://developer.appcelerator.com/question/127816/xhr-not-working-in-ios-5-sdk
Ryan - No, I don't have to leave yet. I'll be available for an additional 2-3 hours, working on this problem, and back in the office early tomorrow morning. For now I've been able to disable the charset information coming through in the Content-Type so that I can continue to test, but your server WILL need to be able to process this information as part of POST for when you upgrade to 1.8 (and this will be a recommended upgrade for iOS). ---- Paul - Without actual reporting information by those users on those tickets, I can't confirm if they're the same problem. We can't resolve all HTTP issues before 1.8 freeze (scheduled for next week) but revising HTTP support is fast becoming an issue which will be addressed very early in the 1.9 development cycle.
Heh. I was just confirming that you have everything you need to dig into it. Appreciate the weekend support!
Stephen - Please let me know what kind of information do you need to fix this.
Harjit - We've been able to resolve this without any additional information on your part. I'm currently going through, testing how many issues this resolves. I've confirmed that it is a bug in iOS 5, regarding an HTTP persistence feature that we take advantage of; turning off this feature is all that's needed to fix it. A pull request will be submitted shortly for us to process internally.
Great. Stephen, what is the timeline on the sdk (1.7.3, 1.7.5) being updated?
Ryan - A backport to 1.7.x will need to be discussed internally, but given that this is a critical issue which affects iOS 5, that is likely. The fix should be internally vetted by the end of day (5PM PST) tomorrow.
Ok, just keep me in the loop. Will this also result in a unit test being added? How extensive is Appcelerator testing, by the way?
Stephen- That's really great. Please let me know when it will be available for download ?
Harjit - Please watch this ticket. It will be marked 'resolved' when the pull request is accepted, and 'closed' once QE has verified the fix in the appropriate release. You may also download CI builds from our build server at any time: http://builds.appcelerator.com.s3.amazonaws.com/index.html Fixes usually appear in CI ~15-20 minutes after they are accepted and merged by pull request. You may be required to start using master (1.8.0 candidate) to pick up this fix.
Note: This fix can be merged into 1_7_X easily if necessary.
Let's go ahead and get this in 1.7.6
Thanks for getting to the bottom of this guys. Do we have an ETA on the 1.7.6 release? We're using a custom sdk now internally.
Ryan - There is unlikely to be an official 1.7.6 release at any point, but I've added this change to our 1_7_X branch, which means you can pick it up from continuous integration within a few minutes.
I just got 1.7.6 and 1.8.0 after this fix. The 1.8.0 version is filename: mobilesdk-1.8.0.v20111109103101-osx.zip and 1.7.6 is mobilesdk-1.7.6.v20111109161100-osx.zip http Basic auth doesn't work on 4.3 and 5.0. I downgraded to 1.7.5 and 4.3 works. 5.0 doesn't work.... Here is the code for which we are using for authentication . Let me know if you need anything else for this to make it debug function setPassportCredentials(data) { if(data.networkOnline == false) { doOfflineMode(data); return; } var xhr = Titanium.Network.createHTTPClient(); Ti.API.info("Server:" + pt.app.CurrentServer()); xhr.open("POST", pt.app.CurrentServer() + "/tabulae?r=" + Date.now()); // set credentials, var authstr = 'Basic ' + Titanium.Utils.base64encode(data.username + ':' + data.password); Ti.API.info("authstr:" + authstr); xhr.setRequestHeader('Authorization', authstr); xhr.setRequestHeader("Content-Type", "text/html; charset=utf-8"); xhr.onreadystatechange = function(aEvt) { Ti.API.info("onreadystatechange login status " + xhr.status); for(var x in xhr.getResponseHeaders()) { Ti.API.info("onreadystatechange cookie " + xhr.getResponseHeaders()[x]); } } xhr.onload = function() { Ti.API.info("login status " + xhr.status); //Ti.API.info("login response " + xhr.responseText); Ti.API.info("cookie " + xhr.getResponseHeader('Set-Cookie')); // this is a hack -- for some reason for the FIRST REQUEST ONLY // we get a 404 regardless of wether login is successful. if(xhr.status == '404' && !data.retry) { Ti.API.info('Retrying once because of 404'); data.retry = true; setPassportCredentials(data); return; } if(xhr.status == '302') { Ti.API.info('Retrying once because of 302'); return; } if(xhr.status == '401' && !data.retry) { alert("Retry"); Ti.API.info('Retrying once because of 404'); data.retry = true; setPassportCredentials(data); return; } // Save values to prefs Ti.App.Properties.setString('USERNAME', data.username); Ti.App.Properties.setString('PASSWORD', data.password); //var secure_url = "https://"+encodeURIComponent(data.username+":"+data.password)+"@"+pt.app.CurrentServer().substring(8); var secure_url = "https://" + encodeURIComponent(data.username) + ":" + encodeURIComponent(data.password) + "@" + pt.app.CurrentServer().substring(8); Ti.App.Properties.setString('SECURE_URL', secure_url); Ti.App.Properties.setString('AUTH_STRING', authstr); //Ti.App.Properties.setString('COOKIE_STRING', xhr.getResponseHeader('Set-Cookie')); Ti.App.fireEvent('app:versionCheck', { data : data }); Ti.App.fireEvent('app:registerdevice', { data : data }); if(!data.keepCurrentWindow) { pt.app.USER_MODEL.queryUserInformation(data.username, function(userInfo, xhr) { pt.app.USER_MODEL.setUserPropertyFromObject(userInfo); var needsPasswordReset = userInfo.needsPasswordReset; Ti.API.info("queryUserInformation callback needsPasswordReset [" + needsPasswordReset + "]"); Ti.API.debug("queryUserInformation: success " + pt.app.USER_MODEL.getUserFromProperty()); // only on success, get the picture Ti.App.fireEvent('app:queryUserInformation.successful', { data : xhr.responseText, "cookie" : Ti.App.Properties.getString('COOKIE_STRING') }); // only on success, get the picture Ti.App.fireEvent('app:login.successful', { data : data.username, mode : 'ONLINE', needsPasswordReset : needsPasswordReset, "cookie" : Ti.App.Properties.getString('COOKIE_STRING') }); }); } xhr.abort(); } xhr.onerror = function(e) { Ti.API.debug("Location:" + xhr.getResponseHeader("Location")); Ti.API.debug("Referrer:" + xhr.getResponseHeader("Referer")); Ti.App.fireEvent("app:http.error", { action : 'login', status : xhr.status, error : e.error }); xhr.abort(); }; Ti.API.info(String.format("username [%s] password [%s]", data.username, data.password)); // clear all cookies xhr.setRequestHeader("Cookie", "PassportID="); xhr.setRequestHeader("Cookie", "PassportKey="); xhr.setRequestHeader("JSESSIONID", "PassportKey="); xhr.send(); }
Tested on Ti Studio 1.0.7.201112061404 Ti Mob SDK 1.8.0.1.v20111207091653 OSX Lion iPhone 4S OS 5.0.1, iPad 2 OS 5.0 Expected behavior of no duplicate requests is shown
Tested with iOS 4.3 and iOs 5 and I can't login. I don't think it fixed the issue which I'm having.
If you're still experiencing failures you may need to downgrade your TLS version. This was issue TIMOB-6311, which includes documentation changes.
Harjit - You may also need to upgrade your server to handle the "charset" content-type information, as mentioned above.
Added label qe-port. Test sample does not work due to server problems.
Reopening to add/remove labels