Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Multipart Uploads not completing when app is terminated by the system in the background #3173

Closed
thezonie opened this issue Oct 28, 2020 · 10 comments
Assignees
Labels
s3 Issues related to S3 work in progress Issues was triaged and investigation done

Comments

@thezonie
Copy link

Describe the bug
Multipart uploads appear to consist of an InitiateMultipartUpload HTTP POST, followed by a series of 5MB chunk PUT requests, finished off by a CompleteMultipartUpload POST containing the chunk info. Once the CompleteMultipartUpload is successful, the uploaded is complete, and the file appears in the S3 bucket.

If the app is terminated by the system while in the background during an upload, all of the 5MB chunk background transfers complete, but there is no final CompleteMultipartUpload POST to finish the transfer. Additionally, the 5MB chunks are re-uploaded periodically, as the system attempts to finish the upload, but it never sends the final CompleteMultipartUpload.

To Reproduce
Steps to reproduce the behavior:

  1. Launch the app using Xcode on an iOS device, and start a multipart upload.
  2. Once the upload starts, background the app by returning to the home screen, and then stop the app using Xcode. This simulates the app being terminated in the background by the system, so the background transfers will continue.

Observed Behavior
Using Charles Proxy or similar, you can see the 5MB chunk uploads complete, but no final CompleteMultipartUpload. The uploaded file does not appear in the S3 bucket.

Expected Behavior
Once all of the 5MB chunk uploads are complete, the final CompleteMultipartUpload request should be made to complete the upload, and the file should appear in the S3 bucket.

If the app is left in the foreground or is sent to the background with an upload running that completes before the system terminates it, the upload completes as expected.

Areas of the SDK you are using (AWSMobileClient, Cognito, Pinpoint, IoT, etc)?
AWSS3TransferUtility

Environment(please complete the following information):

  • SDK Version: 2.18.0
  • Dependency Manager: CocoaPods
  • Swift Version : 5
  • Xcode Version: 11.7

Device Information (please complete the following information):

  • Device: iPhone X
  • iOS Version: iOS 13.7
@ruiguoamz ruiguoamz added the s3 Issues related to S3 label Oct 28, 2020
@ruiguoamz
Copy link
Contributor

Hi, @thezonie

There is one behavior you described I disagree with: If the app is terminated by the system while in the background during an upload, all of the 5MB chunk background transfers complete. I don't think this is correct.

S3TransferUtility does support background upload, the upload will finish if you turn App into background. But the App terminated by system is another discussion, everything will be wiped out from memory completely. The App running in background and the App terminated is not the same thing.

Correct me if I am wrong. Thanks for reaching out.

@ruiguoamz ruiguoamz added the pending-community-response Issue is pending response from the issue requestor label Oct 29, 2020
@thezonie
Copy link
Author

Thanks for the response, @ruiguoamz

Since the S3TransferUtility uses the URLSessionConfiguration.background(withIdentifier:) to create the background URLSession, the transfers will continue in the background if terminated by the system, but not if the app is explicitly terminated by the user:

As per https://developer.apple.com/documentation/foundation/urlsessionconfiguration/1407496-background:

A session configured with this object hands control of the transfers over to the system, which handles the transfers in a separate process. In iOS, this configuration makes it possible for transfers to continue even when the app itself is suspended or terminated.

If an iOS app is terminated by the system and relaunched, the app can use the same identifier to create a new configuration object and session and to retrieve the status of transfers that were in progress at the time of termination. This behavior applies only for normal termination of the app by the system. If the user terminates the app from the multitasking screen, the system cancels all of the session’s background transfers. In addition, the system does not automatically relaunch apps that were force quit by the user. The user must explicitly relaunch the app before transfers can begin again.

@cbommas references the "retrieving the status of the transfers that were in progress at the time of termination" near the
bottom of their comment: #1047 (comment)

Manually relaunching the app into the foreground after the system has terminated it while the background transfers were still in progress and re-instantiating the S3TransferUtility with the same key to reconnect the progress and completion handler blocks is a slightly different use case to this issue, though.

When the app is terminated by the system, once all of the 5MB chunks complete, the app is relaunched in the background when the UIApplicationDelegate handleEventsForBackgroundURLSession is called, which is where I then call AWSS3TransferUtility.interceptApplication(application, handleEventsForBackgroundURLSession: identifier, completionHandler: completionHandler), also as per @cbommas' comment above, but the final CompleteMultipartUpload still does not appear to be called.

@ruiguoamz ruiguoamz self-assigned this Oct 30, 2020
@thezonie
Copy link
Author

thezonie commented Nov 2, 2020

The issue appears to be related to the recovery process, when the app re-registers the S3TransferUtility before calling the interceptApplication method from handleEventsForBackgroundURLSession.

In the linkTransfersToNSURLSession method, the NSURLSession uploadTasks are not properly linked to the associated AWSS3TransferUtilityUploadSubTask objects as it is only looking for AWSS3TransferUtilityUploadTask objects:

if ([obj isKindOfClass:[AWSS3TransferUtilityUploadTask class]])

@palpatim palpatim added follow up Requires follow up from maintainers and removed pending-community-response Issue is pending response from the issue requestor labels Nov 2, 2020
@palpatim
Copy link
Member

palpatim commented Nov 2, 2020

@thezonie Thanks very much for the investigation and link. We'll take a look and update this issue when we have more info.

@lawmicha lawmicha self-assigned this Nov 20, 2020
@ptwobrussell
Copy link

ptwobrussell commented Nov 27, 2020

I believe that I am experiencing the same issue here. For my primary use case of uploading large files like videos, this is essentially a blocker for me to ship my app since it may be incredibly common for for my users to have large multipart uploads terminated by later versions of iOS (due to memory pressure, etc.)

I have some experience with URLSession and will dig in deeper today to see if I can offer any help.

If any of the primary maintainers have a confident prescription for how to fix it or any additional guidance, I will gladly try to provide a patch. I'm also happy to help with testing a patch if anyone is nearly there.

Has anything new been learned since the last comment or an ETA for a patch put in place?

@ptwobrussell
Copy link

ptwobrussell commented Nov 28, 2020

I was able to dig into this a big deeper today, and I've written a short novella because it helps me to better understand what's going on (and hopefully helps someone else who's more familiar with this code to guide me in the right direction...)

  • I think I've developed a decent mental model of the architecture for AWSS3TransferUtility.m now in terms the relationship between a MultipartUploadTask and a UploadSubTask work throughout the code.
  • I was able to get my project environment setup so that I can take advantage of all of the debug logging that's already in place and make local modifications to AWSS3TransferUtility as part of my workflow.
  • I captured the debug logs from a successful 'suspend/resume' multi-part upload.
  • I captured the debugs from an unsuccessful 'terminate/restart' multi-part upload. (This is what we're trying to debug here.)
  • I was able to start analyzing/comparing the logs to see what's happening in each situation.
  • I was able to dig in a bit deeper in a later debugging session

Here's the end of the logging output for the successful suspend/resume situation:

AWSCore debug       21:21:11.007527-0500    interceptApplication called for URLSession [com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo] CognitoAuthSampleApp
AWSCore debug       21:21:11.014697-0500    Setting completion handler for urlSession [com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo]  CognitoAuthSampleApp
AWSCore debug       21:21:11.048620-0500    Thread:<NSThread: 0x2827f47c0>{number = 7, name = (null)}: didCompleteWithError called for task 4   CognitoAuthSampleApp
AWSCore debug       21:21:11.049895-0500    Thread:<NSThread: 0x2827f47c0>{number = 7, name = (null)}: didCompleteWithError called for task 3   CognitoAuthSampleApp
AWSCore debug       21:21:11.051112-0500    Thread:<NSThread: 0x2827f47c0>{number = 7, name = (null)}: didCompleteWithError called for task 2   CognitoAuthSampleApp
AWSCore debug       21:21:11.052135-0500    Thread:<NSThread: 0x2827f47c0>{number = 7, name = (null)}: didCompleteWithError called for task 1   CognitoAuthSampleApp
AWSCore debug       21:21:11.055116-0500    Updating request to use virtual-host style URL  CognitoAuthSampleApp
AWSCore debug       21:21:11.055188-0500    Rewrote request URL to: https://mobile-app-video-uploads-qa.s3.us-east-2.amazonaws.com/public/push-ups-17mb.mp4?uploadId=hYsiLAcTj_i1p52By6bTQl074sIyp3oozLosyrgFpjBtTZgBJRMwMM5B0Zp73FG8nnt8cFXNeRWS22InCIj2yQXIJiy8rHaaQzUfIH9vdAm4GGjDJTNL2iHn4CZLhb.sIJYh30E1vPB7x.8HUnbGmYy6hvr6NbTnmQ7I1wh5NgY-   CognitoAuthSampleApp
AWSCore debug       21:21:11.056133-0500    Request headers:
{   
    Authorization = "AWS4-HMAC-SHA256 Credential=xxx/us-east-2/s3/aws4_request, SignedHeaders=content-type;host;user-agent;x-amz-content-sha256;x-amz-date;x-amz-security-token, Signature=xxx";
    "Content-Type" = "binary/octet-stream";
    Host = "mobile-app-video-uploads-qa.s3.us-east-2.amazonaws.com";
    "User-Agent" = "amplify-iOS/(Function) iOS/14.2 en_US";
    "X-Amz-Date" = 20201128T022111Z;
    "X-Amz-Security-Token" = "xxx"   CognitoAuthSampleApp
AWSCore debug       21:21:11.056257-0500    Request body:

<CompleteMultipartUpload xmlns="http://s3.amazonaws.com/doc/2006-03-01/">
    <Part>
        <ETag>&quot;4fbbbdb4e14473f0ae5244fa45be609c&quot;</ETag>
        <PartNumber>1</PartNumber>
    </Part>
    <Part>
        <ETag>&quot;9b832aea2bb4d5591416376418dab187&quot;</ETag>
        <PartNumber>2</PartNumber>
    </Part>
    <Part>
        <ETag>&quot;7c8e32a874bdd9542f3d1445cba86c8c&quot;</ETag>
        <PartNumber>3</PartNumber>
    </Part> 
    <Part>
        <ETag>&quot;24b958906358149c4eff31aa1e5b0f75&quot;</ETag>
        <PartNumber>4</PartNumber>
    </Part> 
</CompleteMultipartUpload>  CognitoAuthSampleApp

As expected, this was a successful multi-part upload, and I can confirm that the file indeed made it into S3.

Here's some relevant logging output from the unsuccessful terminate/restart situation:

...
AWSCore info        21:24:03.087534-0500    Initiated multipart upload on server: OdmBR9dmoBc5Bh5DDdYNal43bcfJCmOCvEftFFaHGmgxIh2fbacQguYM1wWiIQFB66oOUBTTozU6frwQpX3kHuCN5QG1BGk8Ey16dH4NnXvcGMnrnPO5Kd3QwfYdicNYx.CIH7wp4sNyWG69ru2PqL2vWivh.07O0Oh7VijvqNQ-  CognitoAuthSampleApp
AWSCore info        21:24:03.087624-0500    Concurrency Limit is 5  CognitoAuthSampleApp
AWSCore debug       21:24:03.148307-0500    Added task for part [1] to inProgress list  CognitoAuthSampleApp
AWSCore debug       21:24:03.176800-0500    Added task for part [2] to inProgress list  CognitoAuthSampleApp
AWSCore debug       21:24:03.200325-0500    Added task for part [3] to inProgress list  CognitoAuthSampleApp
AWSCore debug       21:24:03.212025-0500    Added task for part [4] to inProgress list  CognitoAuthSampleApp
AWSCore debug       21:24:03.212157-0500    Starting subTask 3  CognitoAuthSampleApp
AWSCore debug       21:24:03.213361-0500    Starting subTask 2  CognitoAuthSampleApp
AWSCore debug       21:24:03.213867-0500    Starting subTask 1  CognitoAuthSampleApp
AWSCore debug       21:24:03.215256-0500    Starting subTask 4  CognitoAuthSampleApp
AWSCore debug       21:24:03.523612-0500    Total 17534808, ProgressSoFar 1048576   CognitoAuthSampleApp
...
AWSCore debug       21:24:10.124372-0500    Thread:<NSThread: 0x28182c400>{number = 7, name = (null)}: didCompleteWithError called for task 4   CognitoAuthSampleApp
...
AWSCore	debug		21:24:13.168301-0500	Total 17534808, ProgressSoFar 13864792	CognitoAuthSampleApp

<<<<<<<< I terminated the app during the upload with a `kill(getpid(), SIGKILL)` Button action in my app to simulate iOS terminating the app>>>>>>>>

AWSCore	debug		21:24:19.990525-0500	Temporary dir Path is /var/mobile/Containers/Data/Application/52581070-AD56-44BB-91B3-E696C6EDCDBD/Library/Caches/S3TransferUtility	CognitoAuthSampleApp
AWSCore	info		21:24:20.008495-0500	Transfer Utility Database Path: [/var/mobile/Containers/Data/Application/52581070-AD56-44BB-91B3-E696C6EDCDBD/Library/Caches/S3TransferUtility/com/amazonaws/AWSS3TransferUtility/transfer_utility_database]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.008645-0500	In Recovery for TU Session [com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009140-0500	Found MultiPartUpload [01819B0C-95D1-45FF-8D66-C611CDA7F02B] with Multipart ID [OdmBR9dmoBc5Bh5DDdYNal43bcfJCmOCvEftFFaHGmgxIh2fbacQguYM1wWiIQFB66oOUBTTozU6frwQpX3kHuCN5QG1BGk8Ey16dH4NnXvcGMnrnPO5Kd3QwfYdicNYx.CIH7wp4sNyWG69ru2PqL2vWivh.07O0Oh7VijvqNQ-] and status [1]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009226-0500	Found MultiPartUpload SubTask [01819B0C-95D1-45FF-8D66-C611CDA7F02B] with taskNumber [1] and status [2]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009280-0500	Found MultiPartUpload SubTask [01819B0C-95D1-45FF-8D66-C611CDA7F02B] with taskNumber [2] and status [2]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009443-0500	Found MultiPartUpload SubTask [01819B0C-95D1-45FF-8D66-C611CDA7F02B] with taskNumber [3] and status [2]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009500-0500	Found MultiPartUpload SubTask [01819B0C-95D1-45FF-8D66-C611CDA7F02B] with taskNumber [4] and status [3]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009551-0500	Iterating through task Identifier [3]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009603-0500	Iterating through task Identifier [1]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009666-0500	Iterating through task Identifier [2]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.009725-0500	No sessionTask found for taskIdentifier 3	CognitoAuthSampleApp
AWSCore	debug		21:24:20.052687-0500	interceptApplication called for URLSession [com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.052740-0500	Setting completion handler for urlSession [com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.067475-0500	No sessionTask found for taskIdentifier 1	CognitoAuthSampleApp
AWSCore	debug		21:24:20.088346-0500	No sessionTask found for taskIdentifier 2	CognitoAuthSampleApp
AWSCore	debug		21:24:20.115847-0500	Multipart transfer status is [1]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.116018-0500	Moving Task[6] to progress for Multipart[OdmBR9dmoBc5Bh5DDdYNal43bcfJCmOCvEftFFaHGmgxIh2fbacQguYM1wWiIQFB66oOUBTTozU6frwQpX3kHuCN5QG1BGk8Ey16dH4NnXvcGMnrnPO5Kd3QwfYdicNYx.CIH7wp4sNyWG69ru2PqL2vWivh.07O0Oh7VijvqNQ-]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.117021-0500	Moving Task[4] to progress for Multipart[OdmBR9dmoBc5Bh5DDdYNal43bcfJCmOCvEftFFaHGmgxIh2fbacQguYM1wWiIQFB66oOUBTTozU6frwQpX3kHuCN5QG1BGk8Ey16dH4NnXvcGMnrnPO5Kd3QwfYdicNYx.CIH7wp4sNyWG69ru2PqL2vWivh.07O0Oh7VijvqNQ-]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.117683-0500	Moving Task[5] to progress for Multipart[OdmBR9dmoBc5Bh5DDdYNal43bcfJCmOCvEftFFaHGmgxIh2fbacQguYM1wWiIQFB66oOUBTTozU6frwQpX3kHuCN5QG1BGk8Ey16dH4NnXvcGMnrnPO5Kd3QwfYdicNYx.CIH7wp4sNyWG69ru2PqL2vWivh.07O0Oh7VijvqNQ-]	CognitoAuthSampleApp
AWSCore	debug		21:24:20.118259-0500	Thread:<NSThread: 0x2814ecf40>{number = 6, name = (null)}: didCompleteWithError called for task 3	CognitoAuthSampleApp
AWSCore	debug		21:24:20.118310-0500	Unable to find information for task 3 in taskDictionary	CognitoAuthSampleApp
AWSCore	debug		21:24:20.118458-0500	Thread:<NSThread: 0x2814ecf40>{number = 6, name = (null)}: didCompleteWithError called for task 2	CognitoAuthSampleApp
AWSCore	debug		21:24:20.118670-0500	Unable to find information for task 2 in taskDictionary	CognitoAuthSampleApp
AWSCore	debug		21:24:20.118735-0500	URLSessionDidFinishEventsForBackgroundURLSession called for NSURLSession com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo	CognitoAuthSampleApp
AWSCore	debug		21:24:20.118796-0500	Thread:<NSThread: 0x2814ecf40>{number = 6, name = (null)}: didCompleteWithError called for task 1	CognitoAuthSampleApp
AWSCore	debug		21:24:20.118869-0500	Unable to find information for task 1 in taskDictionary	CognitoAuthSampleApp

<<<<<<<< Note the time delay before the next log message appeared >>>>>>>>

AWSCore	debug		21:28:37.327209-0500	interceptApplication called for URLSession [com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo]	CognitoAuthSampleApp
AWSCore	debug		21:28:37.328759-0500	Setting completion handler for urlSession [com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo]	CognitoAuthSamplexApp
AWSCore	debug		21:28:37.357918-0500	Thread:<NSThread: 0x2814ecf40>{number = 6, name = (null)}: didCompleteWithError called for task 6	CognitoAuthSampleApp
AWSCore	debug		21:28:37.359919-0500	Thread:<NSThread: 0x2814ecf40>{number = 6, name = (null)}: didCompleteWithError called for task 4	CognitoAuthSampleApp
AWSCore	debug		21:28:37.362142-0500	URLSessionDidFinishEventsForBackgroundURLSession called for NSURLSession com.amazonaws.AWSS3TransferUtility.Default.Identifier.ai.strongest.foo	CognitoAuthSampleApp
AWSCore	debug		21:28:37.362247-0500	Thread:<NSThread: 0x2814ecf40>{number = 6, name = (null)}: didCompleteWithError called for task 5	CognitoAuthSampleApp
AWSCore	debug		21:28:37.378070-0500	Updating request to use virtual-host style URL	CognitoAuthSampleApp
AWSCore	debug		21:28:37.378216-0500	Rewrote request URL to: https://mobile-app-video-uploads-qa.s3.us-east-2.amazonaws.com/public/push-ups-17mb.mp4?uploadId=OdmBR9dmoBc5Bh5DDdYNal43bcfJCmOCvEftFFaHGmgxIh2fbacQguYM1wWiIQFB66oOUBTTozU6frwQpX3kHuCN5QG1BGk8Ey16dH4NnXvcGMnrnPO5Kd3QwfYdicNYx.CIH7wp4sNyWG69ru2PqL2vWivh.07O0Oh7VijvqNQ-	CognitoAuthSampleApp
AWSCore	debug		21:28:37.380297-0500	Request headers:
{
    Authorization = "AWS4-HMAC-SHA256 Credential=xxx/us-east-2/s3/aws4_request, SignedHeaders=content-type;host;user-agent;x-amz-content-sha256;x-amz-date;x-amz-security-token, Signature=xxx";
    "Content-Type" = "binary/octet-stream";
    Host = "mobile-app-video-uploads-qa.s3.us-east-2.amazonaws.com";
    "User-Agent" = "amplify-iOS/(Function) iOS/14.2 en_US";
    "X-Amz-Date" = 20201128T022837Z;
    "X-Amz-Security-Token" = "xxx"	CognitoAuthSampleApp
AWSCore	debug		21:28:37.635055-0500	Response headers:
{
    Date = "Sat, 28 Nov 2020 02:28:38 GMT";
    Server = AmazonS3;
    "x-amz-id-2" = "bnZJlgaj7rDp8jP3TqEY2JJ+25TCJXC9eprcRNhoYiMoe3nmKxfOp/wTC6jAk6umnB82VVmoke8=";
    "x-amz-request-id" = BE992CFA8A584851;
}	CognitoAuthSampleApp

Here's my interpretation of the logging so far after spending a little bit of time with the XCode debugger [updated]:

  • There were 4 MultiPartUploadSubTasks found in transfer utility's database per "Found MultiPartUpload SubTask..." messages. This is logging out of hydrateFromDB:tempTransferDictionary so this is confirming that the transfer utility knows there should be 4 parts to the upload. This is good and makes sense.
  • There were only 3 messages to the effect of "Iterating through task Identifier..." - This is logging out of a loop defined by for( NSURLSessionUploadTask *task in uploadTasks ) in the method linkTransfersToNSURLSession: tempTransferDictionary:completionHandler. There are only three tasks mentioned here because task 4 already completed as shown in the logs (I'm working with a 17MB test file so there are (3) 5MB chunks and (1) 2MB chunk.)
  • There were 3 messages to the effect of "No sessionTask found for taskIdentifier..." - This is logging out of handleUnlinkedTransfers: tempTransferDictionary (called at the very end of linkTransfersToNSURLSession: tempTransferDictionary:completionHandler
    • This part of the source code is pretty confusing, and some of the comments even seem a bit misleading. For example, there are some "No sessionTask found for taskIdentifier..." messages that are logged. In my experience, the session tasks were found, but they they were ignored, perhaps intentionally since I'm doing a multi-part upload, and the strategy in the source as it's written is to not consider restarting them. Instead, new tasks are spun up...
  • The effect of the "No sessionTask found for taskIdentifier..." messages is that three additional tasks are spun up, and this corresponds to the 3 log messages to the effect of "Moving Task[{4,5,6}] to progress".
    • "Multipart transfer status is [1]" - This is telling us that the transfer is still in progress since
      1=AWSS3TransferUtilityTransferStatusInProgress. This makes sense because we know the multi-part upload didn't successfully complete yet.
  • There are 3 messages to the effect of "Unable to find information for task {1,2,3}" that are logged out of didCompleteWithError
  • And then a few minutes later, some "didCompleteWithError called for task {4,5,6}" messages appear.

After adding some additional logging I discovered that the upload is failing because totalBytesSent != transferUtilityMultiPartUploadTask.contentLength.longLongValue because we have a key in a dictionary that getting clobbered.

Here's what I think is happening:

Someone else should take a look as well, but what I've been able to consistently find by tracing the source.

I'm currently thinking about the best fix for preventing taskIdentifier from being clobbered. This identifier is assigned in createUploadSubTask:subtask:startTransfer:internalDictionaryToAddSubTaskTo, and there are some assumptions throughout the code about these identifiers coming off of the session task. e.g. search for .sessionTask.taskIdentifier to find some of them. The cleanest way to fix it might be to just prevent the key collision since I can't foresee any downstream effects of using a different key based on following the source through to the completion handler.

@ptwobrussell
Copy link

ptwobrussell commented Nov 30, 2020

@palpatim @lawmicha @thezonie - I hope my comments and this PR are helpful in fixing the issue. I'm vested in helping to get this get fixed, so let me know...

@lawmicha
Copy link
Contributor

lawmicha commented Dec 6, 2020

Hi @ptwobrussell, thanks for the deep dive into this issue and the detailed write-up on your investigation. This is really helpful in understanding what's going on in the TransferUtility code. It's clear that the taskIdentifier from NSURLSessionUploadTask does not uniquely identify the parts of the multi-part upload. Taking a look at your PR to help get this going.

@thezonie I tried setting up Charles as the http proxy for my iOS device connected to the macbook and ran into some issues with installing the SSL certificate. I was following this and could not get the device to load the certificate from the safari/chrome broswer, so it may be an issue on my end. Just want get more information on your repro steps

  • Is it a requirement to run this on a device and not the simulator due to the termination scenario?
  • Any special gotchas that you found when installing the Charles Proxy, or does this look like similar steps you did to enable the charles proxy on your iOS device?

@ptwobrussell
Copy link

@lawmicha - awesome!

FWIW, I was able to consistently reproduce without using Charles (though I've previously overcome the SSL issues with my XCode setup; it was tricky for me as well) and could use more fine grained logging to confirm what @thezonie reported.

My PR did resolve the issue so at the very least I think you will be able to confirm that it empirically fixes the bug and see that the patch makes sense once you read it.

There may be better ways of generating unique IDs than what I put forth, though, I feel pretty confident about the core fix

@palpatim palpatim added work in progress Issues was triaged and investigation done and removed follow up Requires follow up from maintainers labels Dec 11, 2020
@lawmicha
Copy link
Contributor

lawmicha commented Dec 17, 2020

Hi @ptwobrussell, thanks for the investigation and testing out the #3282 we've released it in 2.21.0

I will optimisically close this issue, please let us know if you have any issues.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
s3 Issues related to S3 work in progress Issues was triaged and investigation done
Projects
None yet
Development

No branches or pull requests

5 participants