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

Up/download stalls on iMac #152

Open
pascalfribi opened this Issue May 19, 2017 · 12 comments

Comments

Projects
None yet
4 participants
@pascalfribi
Copy link

pascalfribi commented May 19, 2017

Hi,

I am using Dropbox embedded in an application and I have observer a very strange behaviour. On almost all of my devices, up/downloading files with downloadURL:overwrite:destination works well, but on one machine these up/downloads just stall from time to time. Not always, sometimes they work fine, at other attempts they just stall.

It works on all my iOS devices and on my Macbook Pros. But it stalls on my quadcore iMac.

I have traced the problem and added debug statements to the NSURLSession delegates and I see that in case where it stalls, the delegates are not called at all for theses download tasks. I see that the download tasks are created and they are resumes (NSURLDownloadTask), but after that the delegate is never called and the download never finishes. In the cache of the NSURLSession I see that the files are created (with zero 0), so I am sure that the NSURLDownloadTask is actually properly created.

This is not a network problem, because at the same time all my other devices in the same network all work fine.

When I force the DBClientManager to only use Foreground Sessions with the following initialisation then everything works without problems:

DBTransportDefaultConfig *transportConfig = [[DBTransportDefaultConfig alloc] initWithAppKey:DropboxAppKey forceForegroundSession:YES];
[DBClientsManager setupWithTransportConfigDesktop:transportConfig];

Any idea why this happens. I am only starting at most 10 simultaneous downloads at a time, so it cannot be a problem with thread explosion or anything.

This is all tested with 3.0.18

@greg-db

This comment has been minimized.

Copy link
Contributor

greg-db commented May 19, 2017

Thanks for the report! We'll take a look to see if we can figure out what's happening in this case.

vineetchoudhary added a commit to vineetchoudhary/AppBox-iOSAppsWirelessInstallation that referenced this issue May 26, 2017

@scobbe

This comment has been minimized.

Copy link
Contributor

scobbe commented Jun 1, 2017

@pascalfribi: Any update here? Are you still seeing this issue?

Can you also confirm that your app is not in the background when the download finishes? It won't execute your handlers until the app is in the foreground again.

Would you mind updating to 3.1.0 as well?

Given that this is an issue only on your quadcore iMac and not other apple platforms, I'm more inclined to think it's an NSURLSession bug.

I'll see if I can get a hold of an iMac to test this out. Any more specifics you can give about in which cases this problem arises?

@pascalfribi

This comment has been minimized.

Copy link
Author

pascalfribi commented Jun 1, 2017

@scobbe

This comment has been minimized.

Copy link
Contributor

scobbe commented Jun 1, 2017

Thanks for the detailed repro steps. I'll see if I can look into this and try and repro on my end. Thanks!

@fletcher

This comment has been minimized.

Copy link

fletcher commented Sep 11, 2018

This seems to still exist as of 3.9.1.

I noticed occasional difficulty with sync on an iOS app. Certain files would seem to fail to download under various circumstances. I couldn't find a clear reason.

So I built a test app on macOS (my dropbox handling code is cross-platform.) I discovered that I could reliably upload files, but occasionally had trouble downloading a file.

I could reliably reproduce this by creating two test files, which are then uploaded. I then duplicated one of the files in my regular Dropbox folder, so that it is uploaded by the macOS Dropbox app. When my test app received notification of the new file, it attempts to download the file, but fails:

	[[client.filesRoutes downloadData:path]
	 setResponseBlock:^(DBFILESFileMetadata * _Nullable result, DBFILESDownloadError * _Nullable routeError, DBRequestError * _Nullable networkError, NSData * _Nullable fileData) {

No matter how much I tried, the response block was never called.

After finding this thread, I used this in my setup:

DBTransportDefaultConfig *transportConfig = [[DBTransportDefaultConfig alloc] initWithAppKey:@"xxxx" forceForegroundSession:YES];
[DBClientsManager setupWithTransportConfigDesktop:transportConfig];

And at this point syncing seemed to work flawlessly during my tests. I have not tried this on iOS yet.

My test mac environment is a Late 2012 Mac Mini running 10.12.6. (4 cores).

If there is something else useful that I can offer, please let me know.

@greg-db

This comment has been minimized.

Copy link
Contributor

greg-db commented Sep 11, 2018

@fletcher Thanks for the information! I don't believe we were ever able to reproduce this here. Would you be able to provide the test project for reproducing this? Thanks in advance!

@fletcher

This comment has been minimized.

Copy link

fletcher commented Sep 11, 2018

@fletcher

This comment has been minimized.

Copy link

fletcher commented Sep 12, 2018

This seems to replicate it. Create a new Xcode macOS Cocoa App project with the following AppDelegate.m. Replace the dropbox app key with your key.

Run the program in Xcode and watch the output window. The program will upload two fake files to your Dropbox folder. It then checks for updates repeatedly. It should successfully upload the two files, and then successfully download them (though it doesn't save them anywhere.)

Then use the Finder to duplicate one of the files in the Dropbox folder so that the Dropbox client uploads it. You should then get a message attempting to download the new file, but no message indicating successful download.

If you change #define kUseForegroundFixNo 1 to #define kUseForegroundFix 1, then it should work successfully.


//
//  AppDelegate.m
//  FTPDropboxTest
//
//  Created by Fletcher T. Penney on 9/9/18.
//  Copyright © 2018 MultiMarkdown Software, LLC. All rights reserved.
//

#import "AppDelegate.h"

#import <ObjectiveDropboxOfficial/ObjectiveDropboxOfficial.h>

@interface AppDelegate ()

@end

@implementation AppDelegate {
	NSString *			_lastSynchronizedCursor;
}


- (void) applicationWillFinishLaunching:(NSNotification *)notification {
	[[NSAppleEventManager sharedAppleEventManager] setEventHandler:self
													   andSelector:@selector(handleAppleEvent:withReplyEvent:)
													 forEventClass:kInternetEventClass
														andEventID:kAEGetURL];
}


#define kUseForegroundFixNo 1

#define kAppKey @"<APPKEYHERE>"


- (void)applicationDidFinishLaunching:(NSNotification *)aNotification {
	// Get Dropbox Access
#ifdef kUseForegroundFix
	DBTransportDefaultConfig *transportConfig = [[DBTransportDefaultConfig alloc] initWithAppKey:kAppKey forceForegroundSession:YES];
	[DBClientsManager setupWithTransportConfigDesktop:transportConfig];
#else
	[DBClientsManager setupWithAppKeyDesktop:kAppKey];
#endif

	// Get authorization
	if ([DBClientsManager authorizedClient] == NULL) {
		[DBClientsManager authorizeFromControllerDesktop:[NSWorkspace sharedWorkspace]
											  controller:[[[NSApplication sharedApplication] keyWindow] contentViewController]
												 openURL:^(NSURL * _Nonnull localURL) {
													 [[NSWorkspace sharedWorkspace] openURL:localURL];
												 }];
	}

	// Have we previously synchronized with Dropbox?
	_lastSynchronizedCursor = [[NSUserDefaults standardUserDefaults] stringForKey:@"lastDropboxCursor"];
	if (_lastSynchronizedCursor && [_lastSynchronizedCursor isEqualToString:@""]) {
		_lastSynchronizedCursor = NULL;
	}


	// Upload test files to Dropbox Server
	DBUserClient * client = [DBClientsManager authorizedClient];
	NSString * testString = @"FTPDropboxTest";
	NSData * testData = [testString dataUsingEncoding:NSUTF8StringEncoding];
	NSString * uuid = [[NSUUID UUID] UUIDString];

	NSString * path = [@"/" stringByAppendingString:[uuid stringByAppendingString:@"-1.md"]];


	// Upload first file
	NSLog(@"Upload file: %@", path);

	[[client.filesRoutes uploadData:path
						  inputData:testData]
	 setResponseBlock:^(DBFILESFileMetadata * _Nullable result, DBFILESUploadError * _Nullable routeError, DBRequestError * _Nullable networkError) {
		 if (result) {
			 NSLog(@"Uploaded file: %@", path);
		 } else {
			 NSLog(@"Error uploading file: %@", path);
		 }
	 }];

	// Upload second file
	path = [@"/" stringByAppendingString:[uuid stringByAppendingString:@"-2.md"]];
	NSLog(@"Upload file: %@", path);

	[[client.filesRoutes uploadData:path
						  inputData:testData]
	 setResponseBlock:^(DBFILESFileMetadata * _Nullable result, DBFILESUploadError * _Nullable routeError, DBRequestError * _Nullable networkError) {
		 if (result) {
			 NSLog(@"Uploaded file: %@",path);
		 } else {
			 NSLog(@"Error uploading file: %@", path);
		 }
	 }];


	// Check Server for updates until we're killed
	if (_lastSynchronizedCursor) {
		[self getUpdatesFromClient:client sinceCursor:_lastSynchronizedCursor];
	} else {
		[self getFullFileList];
	}
}


- (void) getFullFileList {
	DBUserClient * client = [DBClientsManager authorizedClient];

	[[client.filesRoutes listFolder:@""
						 recursive:@YES
				  includeMediaInfo:@NO
					includeDeleted:@YES
   includeHasExplicitSharedMembers:@NO
			 includeMountedFolders:@YES
							 limit:NULL
						sharedLink:NULL
			 includePropertyGroups:NULL]
	 setResponseBlock:^(DBFILESListFolderResult * _Nullable result, DBFILESListFolderError * _Nullable routeError, DBRequestError * _Nullable networkError) {
		 if (result) {
			 // Handle results
			 [self processEntries:result.entries];

			 self->_lastSynchronizedCursor = result.cursor;
			 [[NSUserDefaults standardUserDefaults] setValue:self->_lastSynchronizedCursor forKey:@"lastDropboxCursor"];

			 if ([result.hasMore boolValue]) {
				 // Keep going
				 [self getUpdatesFromClient:client sinceCursor:self->_lastSynchronizedCursor];
			 } else {
				 // Nothing more to get at this time

				 // Start over
				 [self getUpdatesFromClient:client sinceCursor:self->_lastSynchronizedCursor];
			 }
		 }
	 }];
}

- (void) getUpdatesFromClient:(DBUserClient *) client sinceCursor:(NSString *) cursor {
	[[client.filesRoutes listFolderContinue:cursor]
	 setResponseBlock:^(DBFILESListFolderResult * _Nullable result, DBFILESListFolderContinueError * _Nullable routeError, DBRequestError * _Nullable networkError) {
		 if (result) {
			 // Handle results
			 [self processEntries:result.entries];

			 self->_lastSynchronizedCursor = result.cursor;
			 [[NSUserDefaults standardUserDefaults] setValue:self->_lastSynchronizedCursor forKey:@"lastDropboxCursor"];

			 if ([result.hasMore boolValue]) {
				 //  Keep going
				 [self getUpdatesFromClient:client sinceCursor:self->_lastSynchronizedCursor];
			 } else {
				 // nothing more to get at this time

				 // Start over
				 [self getUpdatesFromClient:client sinceCursor:self->_lastSynchronizedCursor];
			 }
		 }
	 }];
}


- (void) processEntries:(NSArray<DBFILESMetadata *> *) folderEntries {
	for (NSObject * entry in folderEntries) {

		if ([entry isKindOfClass:[DBFILESFileMetadata class]]) {
			// File to process
			DBFILESFileMetadata * file = (DBFILESFileMetadata *) entry;

			NSLog(@"download file: %@", [file pathDisplay]);
			[self downloadFile:[file pathDisplay]];
		} else if ([entry isKindOfClass:[DBFILESFolderMetadata class]]) {
			// This is a folder
		} else if ([entry isKindOfClass:[DBFILESDeletedMetadata class]]) {
			// Entry was deleted
		}
	}
}


- (void) downloadFile:(NSString *) path{
	if (path) {
		DBUserClient * client = [DBClientsManager authorizedClient];

		[[client.filesRoutes downloadData:path]
		 setResponseBlock:^(DBFILESFileMetadata * _Nullable result, DBFILESDownloadError * _Nullable routeError, DBRequestError * _Nullable networkError, NSData * _Nullable fileData) {
			 if (result) {
				 NSLog(@"Downloaded file: %@", path);
			 }
		 }];
	}
}


// custom handler
- (void)handleAppleEvent:(NSAppleEventDescriptor *)event withReplyEvent:(NSAppleEventDescriptor *)replyEvent {
	NSURL *url = [NSURL URLWithString:[[event paramDescriptorForKeyword:keyDirectObject] stringValue]];
	DBOAuthResult *authResult = [DBClientsManager handleRedirectURL:url];
	if (authResult != nil) {
		if ([authResult isSuccess]) {
			NSLog(@"Success! User is logged into Dropbox.");
		} else if ([authResult isCancel]) {
			NSLog(@"Authorization flow was manually canceled by user!");
		} else if ([authResult isError]) {
			NSLog(@"Error: %@", authResult);
		}
		// this forces your app to the foreground, after it has handled the browser redirect
		[[NSRunningApplication currentApplication]
		 activateWithOptions:(NSApplicationActivateAllWindows | NSApplicationActivateIgnoringOtherApps)];
	}
}


- (void)applicationWillTerminate:(NSNotification *)aNotification {
	// Insert code here to tear down your application
}


@end
@greg-db

This comment has been minimized.

Copy link
Contributor

greg-db commented Sep 13, 2018

@fletcher Thanks for putting this together. I just tried this, but the issue initially didn't reproduce for me (even without the fix):

2018-09-13 11:17:04.669586-0400 test_152[76392:14283138] Upload file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-1.md
2018-09-13 11:17:04.678093-0400 test_152[76392:14283138] Upload file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-2.md
2018-09-13 11:17:08.687882-0400 test_152[76392:14283138] Uploaded file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-1.md
2018-09-13 11:17:08.688876-0400 test_152[76392:14283138] download file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-1.md
2018-09-13 11:17:09.363651-0400 test_152[76392:14283138] download file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-2.md
2018-09-13 11:17:09.855003-0400 test_152[76392:14283138] Uploaded file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-2.md
2018-09-13 11:17:47.202183-0400 test_152[76392:14283138] Downloaded file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-2.md
2018-09-13 11:17:47.488900-0400 test_152[76392:14283138] Downloaded file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-1.md
2018-09-13 11:26:12.077936-0400 test_152[76392:14283138] download file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-1 copy.md
2018-09-13 11:26:13.828065-0400 test_152[76392:14283138] Downloaded file: /9FCBE3E9-461E-47D3-9586-24DE88E6467A-1 copy.md

I notice you're not doing any error handling for the downloadData call though. Can you try again and print out routeError and networkError just in case something is failing?

@fletcher

This comment has been minimized.

Copy link

fletcher commented Sep 13, 2018

This is a stripped down version of the original code that does not include all of the original debugging I tried to use to narrow down the issue. You can, of course, add whatever debug logging you like. But when the problem occurs, the response block is not called, so there is nowhere from which to print out routeError and networkError.

More interestingly, I just rebooted my machine (after it was powered down for several hours for unrelated reasons) and now the test fails to demonstrate the problem (in other words the download works successfully.) Restarting the app doesn't fix it. Which fits with my iOS experience where sometimes I successfully sync many files from multiple devices without issue, and other times it gets "stuck" and unable to download new files, even after force quitting the app.

Without being familiar with the underlying dropbox code, it seems that the issue would fit into 1 of 2 scenarios:

  1. There is a timeout situation occurring whereby the response block never gets called because the downloadData method is still waiting? Perhaps if I waited long enough, an error would eventually appear?

  2. An error occurs that does not trigger calling the response block, so it is just silently discarded?

The irregular nature of the issue makes me think about a threading issue. I run the test app and my real app with a variety of diagnostics, but most frequently leave the thread debugging on because that is one of the things I have been focused on. I have not found any thread issues.

I do occasionally get exceptions that occur within the dropbox SDK. Descending the stack trace does not identify any obvious parameter issues in my code (though it's not impossible.) I have not noticed any particular pattern to the exceptions. They are infrequent but not exceptionally rare (perhaps 2 or 3 in the hundred times or so of running the test up while creating and debugging it??) I have not noticed any on-device crashes attributable to Dropbox, only in the simulator.

Perhaps importantly, when I rebooted my mac I had also powered down my network (storm preparations for hurricane). So perhaps the overall network is running a bit "cleaner" in some way that prevents a small issue from occurring that was triggering the dropbox issue?

PS> By the timestamps, it appears that you waited 9 minutes between running the app and duplicating the file (at least on this attempt). That may or may not play a role, but I usually wait a few seconds after successfully downloading the first two files and then proceed.

@greg-db

This comment has been minimized.

Copy link
Contributor

greg-db commented Sep 13, 2018

@fletcher Thanks for the detailed information! I was just checking in case it only appeared that the response block wasn't getting called because you were only printing something in the successful case. It's good to know you already checked that.

Anyway, I wouldn't expect scenario 2; any error should get bubbled back to the response block. Scenario 1 is expected if the network connection is lost (see note), but that wouldn't seem to apply here since we've only been discussing attempts while using a working network connection. That said, given the result you described here, it does seem possible there was a network issue leading to this.

Unfortunately, it will be hard to investigate without a reliable way to reproduce it, but I'll leave this open for the team.

@fletcher

This comment has been minimized.

Copy link

fletcher commented Sep 13, 2018

Yeah -- I was intrigued that the test failed so consistently and then worked after rebooting Mac and my network.

Also, in case it isn't obvious. When the test failed, I would run it again and the first two uploads/downloads would work. It was only the 3rd download that failed to work. Every time.

So perhaps something about uploading "cleared something" (e.g. a buffer or a boolean) that then allowed the download to work properly. But an "unexpected" download, didn't work.

But again, all of this is in the context of a sync program that seems to work properly 95%+ of the time, and a test suite that managed to fail 95%+ of the time (it worked once or twice). But after the reboot it works 100% so far.

If this is ever solved, I hope to hear an explanation. I'd love to understand what set of circumstances causes the failure!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment