Certain API Requests not completing, though logs state otherwise

[AaronRietschlin]

Hello,

I am working on an application and am using to fetch, create and update data on a server. For some reason, a lot of my API requests are not working properly all of a sudden. The main issue is when I am PUTting to my server with some data and I receive a 304 in response. I am using the following method for making the request:

Builders.Any.B b = Ion.with(context).load(httpMethod, url).addHeader(Headers.AUTHORIZATION, Headers.AUTH_PREFIX + authToken);
if (!TextUtils.isEmpty(params)) {
    b.setStringBody(params);
}
if (headers != null) {
    for (Map.Entry<String, String> entry : headers.entrySet()) {
        b.addHeader(entry.getKey(), entry.getValue());
    }
}
b.group(group).asString().withResponse().setCallback(callback);

What happens is that the callback method is never called. I also tried with the following instead:

// Same code as above except the following line: 
try{
  Response<String> response = b.group(group).asString().withResponse().get();
  // This code is never reached. Simply sits until I cancel it and then it will go into the Exception below. 
  Log.d("", "");
} catch(Exception e){
  // Exception catching here...
}

As stated in the code above, the method never finishes. When I cancel, it will go into the exception. The thing I find strange is that, it not only doesn't respect the timeout, but the logs act as if it were completed:

06-23 16:02:07.657  13256-13256/com.myapp.debug D/MyAppApi﹕ (0 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: preparing request
06-23 16:02:07.657  13256-13256/com.myapp.debug D/MyAppApi﹕ (0 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: preparing request
06-23 16:02:07.657  13256-13256/com.myapp.debug I/MyAppApi﹕ (0 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: Using loader: com.koushikdutta.ion.loader.HttpLoader@2b9c2f47
06-23 16:02:07.657  13256-13256/com.myapp.debug I/Choreographer﹕ Skipped 117 frames!  The application may be doing too much work on its main thread.
06-23 16:02:07.657  13256-13370/com.myapp.debug D/MyAppApi﹕ (0 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: Executing request.
06-23 16:02:07.658  13256-13370/com.myapp.debug D/MyAppApi﹕ (1 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: Reusing keep-alive socket
06-23 16:02:07.658  13256-13370/com.myapp.debug V/MyAppApi﹕ (1 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: socket connected
06-23 16:02:07.658  13256-13370/com.myapp.debug V/MyAppApi﹕ (1 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ:
    PUT /services/apexrest/mobile/prm/v2/Tasks/00Tj000000LgtVlEAJ HTTP/1.1
    Host: na16.salesforce.com
    User-Agent: Dalvik/2.1.0 (Linux; U; Android 5.1; Nexus5_5.1 Build/LMY47D)
    Accept-Encoding: gzip, deflate
    Connection: keep-alive
    Accept: */*
    Authorization: Bearer [AUTH_TOKEN_REDACTED]
    Content-Type: application/json
    Cookie: BrowserId=sW3QFnL_SRukVgPsO_RLYg
    Content-Length: 1687
06-23 16:02:07.658  13256-13370/com.myapp.debug V/MyAppApi﹕ (1 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: request completed
06-23 16:02:08.040  13256-13370/com.myapp.debug V/MyAppApi﹕ (382 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: Received headers:
    HTTP/1.1 304 Not Modified
    Date: Tue, 23 Jun 2015 20:02:07 GMT
    Content-Type: application/json;charset=UTF-8
    Transfer-Encoding: chunked
06-23 16:02:08.040  13256-13370/com.myapp.debug D/MyAppApi﹕ (383 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: Response is not cacheable
06-23 16:02:08.040  13256-13370/com.myapp.debug V/MyAppApi﹕ (383 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: Final (post cache response) headers:
    HTTP/1.1 304 Not Modified
    Date: Tue, 23 Jun 2015 20:02:07 GMT
    Content-Type: application/json;charset=UTF-8
    Transfer-Encoding: chunked
06-23 16:02:08.040  13256-13370/com.myapp.debug D/MyAppApi﹕ (383 ms) https://myserver.com/api/v2/Tasks/00Tj000000LgtVlEAJ: Connection successful
06-23 16:02:19.791  13256-13256/com.myapp.debug D/LockChecker:run﹕ isLocked:true elapsedSinceLastActivity:14 timeout:0

Any idea what's going on here?

[zhiduozhang]

I think I'm having a similar problem. Is your code working for any version under 5.1?

[koush]

Can you give me a url I can test against?

[koush]

Simple sample ideally.