Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP

Loading…

SPPlaylistContainer becomes "loaded" before its array is populated #62

Closed
aanand opened this Issue · 21 comments

5 participants

@aanand

It seems that the only way to reliably tell when I've loaded the user's array of playlists is by polling the array's count property. If I listen for the loaded property using the new SPAsyncLoading API, my callback fires before the array is populated.

Here's an example:

-(void)sessionDidLoginSuccessfully:(SPSession *)aSession; {
    NSLog(@"logged in");

    SPSession *session = [SPSession sharedSession];

    [SPAsyncLoading waitUntilLoaded:session then:^(NSArray *loadedItems){
        NSLog(@"loaded session");

        [SPAsyncLoading waitUntilLoaded:session.userPlaylists then:^(NSArray *loadedItems) {
            NSLog(@"loaded playlist container");

            [self loadPlaylists];
        }];
    }];
}

-(void)loadPlaylists
{
    SPPlaylistContainer *container = [SPSession sharedSession].userPlaylists;

    NSLog(@"container.loaded = %d, container.playlists.count = %d", container.loaded, container.playlists.count);

    if (container.playlists.count == 0) {
        [self performSelector:@selector(loadPlaylists) withObject:nil afterDelay:1.0];
        return;
    }
}

This outputs the following:

2012-05-22 14:57:29.618 SpotifyTest[5205:10703] logged in
2012-05-22 14:57:29.620 SpotifyTest[5205:10703] loaded session
2012-05-22 14:57:29.620 SpotifyTest[5205:10703] loaded playlist container
2012-05-22 14:57:29.620 SpotifyTest[5205:10703] container.loaded = 1, container.playlists.count = 0
2012-05-22 14:57:30.621 SpotifyTest[5205:10703] container.loaded = 1, container.playlists.count = 21

I would have expected container.playlists.count to be 21 as soon as container.loaded became true, but as the log shows, there was a further delay.

This is a problem for two reasons:

  1. It means I have to use polling, which is ugly (and discouraged by the README)
  2. There's no way to tell whether the playlists haven't loaded or the user simply doesn't have any - in the latter case, the above code will run forever.

Is it possible I've misunderstood the correct way to use SPPlaylistContainer, and there is in fact a way to unambiguously tell when the playlists have loaded?

@iKenndac
Collaborator

Where are you on the 2.0-dev branch? There's been a lot of code flux in there lately, and a number of bugs similar to this one have been fixed. Please try again with the HEAD of that branch.

If it's still broken, please fork CocoaLibSpotify, modify the "test3PlaylistContainer" test in SPPlaylistTests.m to fail then issue a pull request - I can then fix it for you.

@aanand

I'm running against d39f9c6 ("Unit tests no longer bail out if any SPSessionTests fail.")

I've been attempting for the last 2 hours to reproduce this bug in the test suite, with no success at all. I initially thought the other tests might have been interfering, but deleting/disabling everything other than test3SessionLogin and test3PlaylistContainer had no effect - it behaves reliably in the unit test project, and not in mine.

Here's what my method looks like:

-(void)loadPlaylists
{
    SPSession *session = [SPSession sharedSession];

    NSLog(@"***************");
    NSLog(@"start of method");
    NSLog(@"  session.loaded = %d", session.loaded);
    NSLog(@"  session.userPlaylists.loaded = %d", session.userPlaylists.loaded);
    NSLog(@"loading session...");

    [SPAsyncLoading waitUntilLoaded:session then:^(NSArray *loadedSession) {

        SPPlaylistContainer *container = session.userPlaylists;
        NSLog(@"...session loaded");
        NSLog(@"  container.playlists.count = %d", container.playlists.count);
        NSLog(@"loading playlist container...");

        [SPAsyncLoading waitUntilLoaded:container timeout:15.0 then:^(NSArray *loadedItems, NSArray *notLoadedItems) {
            NSLog(@"...playlist container loaded");
            NSLog(@"  container.loaded = %d", container.loaded);
            NSLog(@"  container.owner = %@", container.owner);
            NSLog(@"  container.playlists.count = %d", container.playlists.count);

            if (container.owner == nil) {
                [self performSelector:_cmd withObject:nil afterDelay:1.0];
            }
        }];
    }];
}

If I run that, I get output like the following:

objc[13650]: Object 0x847a570 of class __NSCFData autoreleased with no pool in place - just leaking - break on objc_autoreleaseNoPool() to debug
2012-05-22 18:18:26.999 SpotifyTest[13650:10703] logged in
2012-05-22 18:18:27.000 SpotifyTest[13650:10703] ***************
2012-05-22 18:18:27.000 SpotifyTest[13650:10703] start of method
2012-05-22 18:18:27.001 SpotifyTest[13650:10703]   session.loaded = 0
2012-05-22 18:18:27.002 SpotifyTest[13650:10703]   session.userPlaylists.loaded = 0
2012-05-22 18:18:27.002 SpotifyTest[13650:10703] loading session...
2012-05-22 18:18:27.003 SpotifyTest[13650:10703] ...session loaded
2012-05-22 18:18:27.004 SpotifyTest[13650:10703]   container.playlists.count = 0
2012-05-22 18:18:27.005 SpotifyTest[13650:10703] loading playlist container...
2012-05-22 18:18:27.006 SpotifyTest[13650:10703] ...playlist container loaded
2012-05-22 18:18:27.007 SpotifyTest[13650:10703]   container.loaded = 1
2012-05-22 18:18:27.008 SpotifyTest[13650:10703]   container.owner = (null)
2012-05-22 18:18:27.009 SpotifyTest[13650:10703]   container.playlists.count = 0
2012-05-22 18:18:28.010 SpotifyTest[13650:10703] ***************
2012-05-22 18:18:28.011 SpotifyTest[13650:10703] start of method
2012-05-22 18:18:28.011 SpotifyTest[13650:10703]   session.loaded = 1
2012-05-22 18:18:28.012 SpotifyTest[13650:10703]   session.userPlaylists.loaded = 1
2012-05-22 18:18:28.013 SpotifyTest[13650:10703] loading session...
2012-05-22 18:18:28.013 SpotifyTest[13650:10703] ...session loaded
2012-05-22 18:18:28.014 SpotifyTest[13650:10703]   container.playlists.count = 0
2012-05-22 18:18:28.015 SpotifyTest[13650:10703] loading playlist container...
2012-05-22 18:18:28.015 SpotifyTest[13650:10703] ...playlist container loaded
2012-05-22 18:18:28.016 SpotifyTest[13650:10703]   container.loaded = 1
2012-05-22 18:18:28.016 SpotifyTest[13650:10703]   container.owner = (null)
2012-05-22 18:18:28.017 SpotifyTest[13650:10703]   container.playlists.count = 0
2012-05-22 18:18:29.018 SpotifyTest[13650:10703] ***************
2012-05-22 18:18:29.019 SpotifyTest[13650:10703] start of method
2012-05-22 18:18:29.019 SpotifyTest[13650:10703]   session.loaded = 1
2012-05-22 18:18:29.020 SpotifyTest[13650:10703]   session.userPlaylists.loaded = 1
2012-05-22 18:18:29.020 SpotifyTest[13650:10703] loading session...
2012-05-22 18:18:29.021 SpotifyTest[13650:10703] ...session loaded
2012-05-22 18:18:29.021 SpotifyTest[13650:10703]   container.playlists.count = 21
2012-05-22 18:18:29.022 SpotifyTest[13650:10703] loading playlist container...
2012-05-22 18:18:29.023 SpotifyTest[13650:10703] ...playlist container loaded
2012-05-22 18:18:29.023 SpotifyTest[13650:10703]   container.loaded = 1
2012-05-22 18:18:29.024 SpotifyTest[13650:10703]   container.owner = <SPUser: 0x817d750>: (null)
2012-05-22 18:18:29.024 SpotifyTest[13650:10703]   container.playlists.count = 21

The number of times it outputs that chunk of debug information with container.loaded = 1 and container.owner = (null) varies unpredictably between 1 and 3.

When I copy and paste this exact code into the body of test3PlaylistContainer (replacing the test code) and run it, I reliably get this output every time:

---- Starting 2 tests in SPSessionTests ----
Running test ValidSessionInit... Passed.
Running test SessionLogin...objc[13920]: Object 0x8452910 of class __NSCFData autoreleased with no pool in place - just leaking - break on objc_autoreleaseNoPool() to debug
2012-05-22 18:20:07.955 CocoaLSTests[13920:10703] logged in
 Passed.
---- Tests in SPSessionTests complete with 2 passed, 0 failed ----
---- Starting 1 tests in SPPlaylistTests ----
Running test PlaylistContainer...2012-05-22 18:20:07.957 CocoaLSTests[13920:10703] ***************
2012-05-22 18:20:07.958 CocoaLSTests[13920:10703] start of method
2012-05-22 18:20:07.959 CocoaLSTests[13920:10703]   session.loaded = 0
2012-05-22 18:20:07.961 CocoaLSTests[13920:10703]   session.userPlaylists.loaded = 0
2012-05-22 18:20:07.964 CocoaLSTests[13920:10703] loading session...
2012-05-22 18:20:07.971 CocoaLSTests[13920:10703] ...session loaded
2012-05-22 18:20:07.972 CocoaLSTests[13920:10703]   container.playlists.count = 0
2012-05-22 18:20:07.974 CocoaLSTests[13920:10703] loading playlist container...
2012-05-22 18:20:07.976 CocoaLSTests[13920:10703] ...playlist container loaded
2012-05-22 18:20:07.978 CocoaLSTests[13920:10703]   container.loaded = 1
2012-05-22 18:20:07.980 CocoaLSTests[13920:10703]   container.owner = <SPUser: 0x846ba40>: (null)
2012-05-22 18:20:07.981 CocoaLSTests[13920:10703]   container.playlists.count = 21

So I'm somewhat at a loss. I don't know what could be causing the non-deterministic behaviour. I've put my entire ApplicationDelegate class up at https://gist.github.com/2770438 - maybe there's something weird I'm doing, but it looks pretty boilerplate to me.

Sorry I can't be of any more help - I realise it's frustrating to be told a bug isn't reproducible, but hopefully you'll spot something amiss.

@iKenndac
Collaborator

Woah, that is indeed weird. I'll take a look at it. Is all this happening on the same platform (i.e., simulator or real device)?

@aanand
@triboud

Hi! I might have the same issue on my iPhone project:
When I try to load the user playlists I only get the starred and inbox playlists, but If I retry 1 second later I get everything properly.
I also have the issue on unit tests and samples (using device or simulator)
It only "seems" to works when the device doesn't have the Spotify App application installed, because the data is fetched during the "Get Spotify!" popup.

Any workarounds would help, Thanks!

@iKenndac
Collaborator

Code sample please.

The "Get Spotify" popup has no effect on the rest of the library — it's just a UIWebView. It sounds like something else is going on here.

@triboud

I guess the popup only gives time to the application to load the missing data...

This code is from the sample Guess The Intro

I only removed the starredPlaylist and inboxPlaylist to highlight my issue.

-(void)waitAndFillTrackPool {

    [SPAsyncLoading waitUntilLoaded:[SPSession sharedSession] then:^(NSArray *loadedession) {

        // The session is logged in and loaded — now wait for the userPlaylists to load.
        NSLog(@"[%@ %@]: %@", NSStringFromClass([self class]), NSStringFromSelector(_cmd), @"Session loaded.");

        [SPAsyncLoading waitUntilLoaded:[SPSession sharedSession].userPlaylists then:^(NSArray *loadedContainers) {

            // User playlists are loaded — wait for playlists to load their metadata.
            NSLog(@"[%@ %@]: %@", NSStringFromClass([self class]), NSStringFromSelector(_cmd), @"Container loaded.");

            NSMutableArray *playlists = [NSMutableArray array];
//          [playlists addObject:[SPSession sharedSession].starredPlaylist];
//          [playlists addObject:[SPSession sharedSession].inboxPlaylist];
            [playlists addObjectsFromArray:[SPSession sharedSession].userPlaylists.flattenedPlaylists];

            [SPAsyncLoading waitUntilLoaded:playlists timeout:3.0 then:^(NSArray *loadedPlaylists, NSArray *notLoadedPlaylists) {

                // All of our playlists have loaded their metadata — wait for all tracks to load their metadata.
                NSLog(@"[%@ %@]: %@ of %@ playlists loaded.", NSStringFromClass([self class]), NSStringFromSelector(_cmd), 
                      [NSNumber numberWithInteger:loadedPlaylists.count], [NSNumber numberWithInteger:loadedPlaylists.count + notLoadedPlaylists.count]);

                NSArray *playlistItems = [loadedPlaylists valueForKeyPath:@"@unionOfArrays.items"];
                NSArray *tracks = [self tracksFromPlaylistItems:playlistItems];

                [SPAsyncLoading waitUntilLoaded:tracks timeout:3.0 then:^(NSArray *loadedTracks, NSArray *notLoadedTracks) {

                    // All of our tracks have loaded their metadata. Hooray!
                    NSLog(@"[%@ %@]: %@ of %@ tracks loaded.", NSStringFromClass([self class]), NSStringFromSelector(_cmd), 
                          [NSNumber numberWithInteger:loadedTracks.count], [NSNumber numberWithInteger:loadedTracks.count + notLoadedTracks.count]);

                    NSMutableArray *theTrackPool = [NSMutableArray arrayWithCapacity:loadedTracks.count];

                    for (SPTrack *aTrack in loadedTracks) {
                        if (aTrack.availability == SP_TRACK_AVAILABILITY_AVAILABLE && [aTrack.name length] > 0)
                            [theTrackPool addObject:aTrack];
                    }

                    self.trackPool = [NSMutableArray arrayWithArray:[[NSSet setWithArray:theTrackPool] allObjects]];
                    // ^ Thin out duplicates.

                    [self startNewRound];

                }];
            }];
        }];
    }];
}

With the popup "Get Spotify" I get the output:

2012-06-16 17:14:26.067 Guess The Intro[46223:10703] [Guess_The_IntroViewController waitAndFillTrackPool]: Session loaded.
2012-06-16 17:14:26.071 Guess The Intro[46223:10703] [Guess_The_IntroViewController waitAndFillTrackPool]: Container loaded.
2012-06-16 17:14:26.072 Guess The Intro[46223:10703] [Guess_The_IntroViewController waitAndFillTrackPool]: 108 of 108 playlists loaded.
2012-06-16 17:14:26.079 Guess The Intro[46223:10703] [Guess_The_IntroViewController waitAndFillTrackPool]: 4496 of 4496 tracks loaded.

Without the popup (and with the Spotify App installed):

2012-06-16 17:19:49.922 Guess The Intro[8063:707] [Guess_The_IntroViewController waitAndFillTrackPool]: Session loaded.
2012-06-16 17:19:50.180 Guess The Intro[8063:707] [Guess_The_IntroViewController waitAndFillTrackPool]: Container loaded.
2012-06-16 17:19:58.078 Guess The Intro[8063:707] [Guess_The_IntroViewController waitAndFillTrackPool]: 0 of 0 playlists loaded.
2012-06-16 17:20:14.016 Guess The Intro[8063:707] [Guess_The_IntroViewController waitAndFillTrackPool]: 0 of 0 tracks loaded.
@iKenndac
Collaborator

Oh right, I see — you should probably increase the timeout on the call to SPAsyncLoading that waits for the playlists to load — 3 seconds is quite short. Playlists are cached locally and will continue to load while the application is running, so it's likely they loaded just after the callback and were then cached for faster loading next time.

@triboud

Hm.. I guess if it is a timeout issue I should have 108 not loaded playlists?

I edited the code to test without timeout, and I still have the same issue:

-(void)waitAndFillTrackPool {

    [SPAsyncLoading waitUntilLoaded:[SPSession sharedSession] then:^(NSArray *loadedession) {

        // The session is logged in and loaded — now wait for the userPlaylists to load.
        NSLog(@"[%@ %@]: %@", NSStringFromClass([self class]), NSStringFromSelector(_cmd), @"Session loaded.");

        [SPAsyncLoading waitUntilLoaded:[SPSession sharedSession].userPlaylists then:^(NSArray *loadedContainers) {

            // User playlists are loaded — wait for playlists to load their metadata.
            NSLog(@"[%@ %@]: %@", NSStringFromClass([self class]), NSStringFromSelector(_cmd), @"Container loaded.");

            NSMutableArray *playlists = [NSMutableArray array];
//          [playlists addObject:[SPSession sharedSession].starredPlaylist];
//          [playlists addObject:[SPSession sharedSession].inboxPlaylist];
            [playlists addObjectsFromArray:[SPSession sharedSession].userPlaylists.flattenedPlaylists];

            [SPAsyncLoading waitUntilLoaded:playlists then:^(NSArray *loadedPlaylists) {

                // All of our playlists have loaded their metadata — wait for all tracks to load their metadata.
                NSLog(@"[%@ %@]: %@ playlists loaded.", NSStringFromClass([self class]), NSStringFromSelector(_cmd), 
                      [NSNumber numberWithInteger:loadedPlaylists.count]);

                NSArray *playlistItems = [loadedPlaylists valueForKeyPath:@"@unionOfArrays.items"];
                NSArray *tracks = [self tracksFromPlaylistItems:playlistItems];

                [SPAsyncLoading waitUntilLoaded:tracks then:^(NSArray *loadedTracks) {

                    // All of our tracks have loaded their metadata. Hooray!
                    NSLog(@"[%@ %@]: %@ tracks loaded.", NSStringFromClass([self class]), NSStringFromSelector(_cmd), 
                          [NSNumber numberWithInteger:loadedTracks.count], [NSNumber numberWithInteger:loadedTracks.count]);

                    NSMutableArray *theTrackPool = [NSMutableArray arrayWithCapacity:loadedTracks.count];

                    for (SPTrack *aTrack in loadedTracks) {
                        if (aTrack.availability == SP_TRACK_AVAILABILITY_AVAILABLE && [aTrack.name length] > 0)
                            [theTrackPool addObject:aTrack];
                    }

                    self.trackPool = [NSMutableArray arrayWithArray:[[NSSet setWithArray:theTrackPool] allObjects]];
                    // ^ Thin out duplicates.

                    [self startNewRound];

                }];
            }];
        }];
    }];
}
Guess The Intro[8122:707] [Guess_The_IntroViewController waitAndFillTrackPool]: Session loaded.
2012-06-16 17:44:15.862 Guess The Intro[8122:707] [Guess_The_IntroViewController waitAndFillTrackPool]: Container loaded.
2012-06-16 17:44:15.866 Guess The Intro[8122:707] [Guess_The_IntroViewController waitAndFillTrackPool]: 0 playlists loaded.
2012-06-16 17:44:15.869 Guess The Intro[8122:707] [Guess_The_IntroViewController waitAndFillTrackPool]: 0 tracks loaded.

Thanks for your help!

@iKenndac
Collaborator

Wait, I've just spotted that in your first example it said "0 of 0 playlists", which means your playlist container is empty. You might be running into this: #35

I'll look into it.

@triboud

I was using my Spotify login, and I just tried with Facebook... Still the same, but yes it looks a bit similar...

@kylefleming

I'm encountering the same issue. It only happens the first time after the user logs in. If the login is remembered, the next time the app is launched it works fine. The only way I can reliable get it to work is to reinstall the app each time. If I try to set up a unit test for this is doesn't work, presumably because of the earlier tests loading the right data. Logging out and back in doesn't work, with or without the same SPSession object (probably because of some sort of cache). Trying to reinitialize the SPSession causes all sorts of problems. I think I might create a separate unit test target to test this issue unless you can think of a better way to test.

Ultimately I need a find or create playlist by name method (preferably atomic), so if you have a better solution that will avoid this bug, I'd love to hear it.

@aanand
@iKenndac
Collaborator

Please create a failing unit test — it's the only wait I can reliably reproduce the problem and fix it.

@iKenndac iKenndac referenced this issue from a commit
Daniel Kennett Add test for GitHub Issue #62 bd33f45
@iKenndac
Collaborator

Thanks for the unit test! I didn't pull it into the main repo since creating a completely new target for it seemed a bit excessive - you're absolutely welcome and encouraged to modify the existing stuff!

Anyway, I couldn't reproduce it myself, but I did find a suspect line of code that looks like it'd cause this issue in some circumstances. Please check out the latest master and see if it helps.

@iKenndac
Collaborator

Closing this to keep the issue list somewhat sane — please reopen if the above commits didn't fix.

@iKenndac iKenndac closed this
@triboud

The issue was still happening for me after the last update, but I finally managed to fix it in a dirty way.
I found out that my problem was related to the cache, which get corrupted somehow, so now I just clear every folders related to CocoaLibSpotify after logout and before login, and everything works fine.
I could not figure out why my cache get corrupted, I will try to make a failing unit test about this.

@triboud triboud referenced this issue
Closed

Issue #62 #76

@triboud

OK I found out why.
It seems that, just after being loaded, the SPPlaylistContainer in [SPSession sharedSession].userPlaylists isn't reliable:

    SPSession* session = [SPSession sharedSession];
    SPPlaylistContainer *container = session.userPlaylists;

    [SPAsyncLoading waitUntilLoaded:container timeout:kSPAsyncLoadingDefaultTimeout then:^(NSArray *loadedItems, NSArray *notLoadedItems) {

        if (container.isLoaded)
            NSLog(@"Container is loaded");
        else
            NSLog(@"Container is not loaded");
        if (session.userPlaylists.isLoaded)
            NSLog(@"session.userPlaylists is loaded");
        else
            NSLog(@"session.userPlaylists is not loaded");

        NSAssert(container == session.userPlaylists, @"Container Changed!");
    }];
Container is loaded
session.userPlaylists is loaded
Logout
Login
Container is loaded
session.userPlaylists is not loaded
Container Changed!

At first this test works, but after logout and login it fails and 'container' is properly loaded but not [SPSession sharedSession].userPlaylists.

I submitted a failing Unit test about this, I'm not sure if it is a real issue, I guess I should always use the values in 'loadedItems', but the sample 'Guess the intro' shows otherwise.

@iKenndac
Collaborator

That's probably an oversight in the sample projects. Thanks for the unit test — I'll get onto fixing it.

@iKenndac iKenndac reopened this
@iKenndac iKenndac closed this
@iKenndac
Collaborator

Just found the base cause of this issue. Thanks for your messages @triboud, they were super helpful! The fix is currently in dev — I'd appreciate it if you could verify the fix.

@iKenndac iKenndac reopened this
@iKenndac iKenndac closed this
@aaresta

Where is the fix? I have the same problem....:)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.