ios cocoa-touch core-data core-data-migration

Can anyone offer advice on debugging this core data migration issue?

I just performed a HeavyWeight core migration - im not sure where the line is between heavyweight and lightweight - this one involved 5 mappings and 1 custom class. I can certainly provide any of these. It seems to me that perhaps it may have been successful - my app is launching and it gets all the way to viewDidLoad - its only when it tries to do a fetchRequest that it crashes. I would appreciate any help debugging the following error message. I have some questions:

Did the migration work? Any way to know if it worked and if this is an issue with my fetch request or if somehow the data was corrupted or if it never worked at all. What is the best way to check this?
Why are there so many question marks in the SQL - does the mean that the migration is not working properly?
What is Z? all of the attributes seem to start with Z - "WHERE t0.ZNOTES IS NOT NULL for instance"
What is an NSSymbolicExpression? Where would it occur in the core data migration. I understand that somehow its trying to find the length of this object, and the object doesn't have that instance method. Does that mean it is assuming the migration is completed when it hasn't been for instance?

Information on any of the above would be greatly appreciated - including resources for where to find this/read more. I have been trying to learn about the migrations in apples documentation but am having trouble. Its been so trying... anything helps, thanks :)

CoreData: annotation: Connecting to sqlite database file at "/Users/alexmarshall/Library/Developer/CoreSimulator/Devices/252E29AE-83C0-4063-8000-C4302854B529/data/Containers/Data/Application/2AC9D1D5-AA70-4236-B9C5-E5C711C4AF28/Library/Application Support/SweatNetOffline.sqlite"
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_METADATA'
CoreData: sql: pragma recursive_triggers=1
CoreData: sql: pragma journal_mode=wal
CoreData: sql: SELECT Z_VERSION, Z_UUID, Z_PLIST FROM Z_METADATA
CoreData: annotation: Connecting to sqlite database file at "/Users/alexmarshall/Library/Developer/CoreSimulator/Devices/252E29AE-83C0-4063-8000-C4302854B529/data/Containers/Data/Application/2AC9D1D5-AA70-4236-B9C5-E5C711C4AF28/Library/Application Support/SweatNetOffline.sqlite"
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_METADATA'
CoreData: sql: SELECT Z_VERSION, Z_UUID, Z_PLIST FROM Z_METADATA
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_METADATA'
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'ACHANGE'
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'ATRANSACTIONSTRING'
CoreData: annotation: Connecting to sqlite database file at "/Users/alexmarshall/Library/Developer/CoreSimulator/Devices/252E29AE-83C0-4063-8000-C4302854B529/data/Containers/Data/Application/2AC9D1D5-AA70-4236-B9C5-E5C711C4AF28/Library/Application Support/.SweatNetOffline.sqlite.migrationdestination_41b5a6b5c6e848c462a8480cd24caef3"
CoreData: annotation: creating schema.
CoreData: sql: pragma page_size=4096
CoreData: sql: pragma auto_vacuum=2
CoreData: sql: BEGIN EXCLUSIVE
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_METADATA'
CoreData: sql: CREATE TABLE ZRECORD ( Z_PK INTEGER PRIMARY KEY, Z_ENT INTEGER, Z_OPT INTEGER, ZRECORDTYPE INTEGER, ZSKILL INTEGER, ZTIMESTAMP TIMESTAMP, ZIMAGEFILENAME VARCHAR, ZTEXT VARCHAR, ZTHUMBNAILFILENAME VARCHAR, ZVIDEOFILENAME VARCHAR ) 
CoreData: sql: CREATE TABLE ZSKILL ( Z_PK INTEGER PRIMARY KEY, Z_ENT INTEGER, Z_OPT INTEGER, ZMETADATA INTEGER, ZNAME VARCHAR ) 
CoreData: sql: CREATE TABLE ZSKILLMETADATA ( Z_PK INTEGER PRIMARY KEY, Z_ENT INTEGER, Z_OPT INTEGER, ZDIFFICULTY INTEGER, ZISACTIVE INTEGER, ZSKILL INTEGER, ZLATESTUPDATE TIMESTAMP, ZSECTIONIDENTIFIER VARCHAR, ZTHUMBNAIL BLOB ) 
CoreData: sql: CREATE INDEX IF NOT EXISTS ZRECORD_ZSKILL_INDEX ON ZRECORD (ZSKILL)
CoreData: sql: CREATE INDEX IF NOT EXISTS ZRECORD_Z_ENT_INDEX ON ZRECORD (Z_ENT)
CoreData: sql: CREATE INDEX IF NOT EXISTS ZSKILL_ZMETADATA_INDEX ON ZSKILL (ZMETADATA)
CoreData: sql: CREATE INDEX IF NOT EXISTS ZSKILLMETADATA_ZSKILL_INDEX ON ZSKILLMETADATA (ZSKILL)
CoreData: annotation: Creating primary key table.
CoreData: sql: CREATE TABLE Z_PRIMARYKEY (Z_ENT INTEGER PRIMARY KEY, Z_NAME VARCHAR, Z_SUPER INTEGER, Z_MAX INTEGER)
CoreData: sql: INSERT INTO Z_PRIMARYKEY(Z_ENT, Z_NAME, Z_SUPER, Z_MAX) VALUES(1, 'Record', 0, 0)
CoreData: sql: INSERT INTO Z_PRIMARYKEY(Z_ENT, Z_NAME, Z_SUPER, Z_MAX) VALUES(2, 'ImageRecord', 1, 0)
CoreData: sql: INSERT INTO Z_PRIMARYKEY(Z_ENT, Z_NAME, Z_SUPER, Z_MAX) VALUES(3, 'TextRecord', 1, 0)
CoreData: sql: INSERT INTO Z_PRIMARYKEY(Z_ENT, Z_NAME, Z_SUPER, Z_MAX) VALUES(4, 'VideoRecord', 1, 0)
CoreData: sql: INSERT INTO Z_PRIMARYKEY(Z_ENT, Z_NAME, Z_SUPER, Z_MAX) VALUES(5, 'Skill', 0, 0)
CoreData: sql: INSERT INTO Z_PRIMARYKEY(Z_ENT, Z_NAME, Z_SUPER, Z_MAX) VALUES(6, 'SkillMetaData', 0, 0)
CoreData: sql: CREATE TABLE Z_METADATA (Z_VERSION INTEGER PRIMARY KEY, Z_UUID VARCHAR(255), Z_PLIST BLOB)
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_METADATA'
CoreData: sql: DELETE FROM Z_METADATA WHERE Z_VERSION = ?
CoreData: sql: INSERT INTO Z_METADATA (Z_VERSION, Z_UUID, Z_PLIST) VALUES (?, ?, ?)
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_MODELCACHE'
CoreData: sql: CREATE TABLE Z_MODELCACHE (Z_CONTENT BLOB)
CoreData: sql: INSERT INTO Z_MODELCACHE (Z_CONTENT) VALUES (?)
CoreData: sql: COMMIT
CoreData: sql: pragma recursive_triggers=1
CoreData: sql: pragma journal_mode
CoreData: sql: SELECT Z_VERSION, Z_UUID, Z_PLIST FROM Z_METADATA
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_METADATA'
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_MODELCACHE'
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'ACHANGE'
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'ATRANSACTIONSTRING'
CoreData: sql: BEGIN EXCLUSIVE
CoreData: sql: SELECT TBL_NAME FROM SQLITE_MASTER WHERE TBL_NAME = 'Z_METADATA'
CoreData: sql: DELETE FROM Z_METADATA WHERE Z_VERSION = ?
CoreData: sql: INSERT INTO Z_METADATA (Z_VERSION, Z_UUID, Z_PLIST) VALUES (?, ?, ?)
CoreData: sql: COMMIT
CoreData: sql: pragma page_count
CoreData: annotation: sql execution time: 0.0002s
CoreData: sql: pragma freelist_count
CoreData: annotation: sql execution time: 0.0001s
CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZLATESTUPDATE, t0.ZNAME, t0.ZUUID FROM ZTAG t0 
CoreData: annotation: sql connection fetch time: 0.0004s
CoreData: annotation: total fetch execution time: 0.0008s for 1 rows.
CoreData: sql: SELECT t0.Z_ENT, t0.Z_PK, Z_FOK_1POSTS FROM ZPOST t0 JOIN Z_1TAGS t1 ON t0.Z_PK = t1.Z_1POSTS WHERE t1.Z_2TAGS = ? 
CoreData: annotation: sql connection fetch time: 0.0005s
CoreData: annotation: total fetch execution time: 0.0006s for 1 rows.
CoreData: annotation: to-many relationship fault "posts" for objectID 0x9de26d27ef2a7aca <x-coredata://DDA9D961-398D-4C5C-8DAA-919F17139695/Tag/p1> fulfilled from database.  Got 1 rows
CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZISVIDEO, t0.ZMEDIAFILENAME, t0.ZNOTES, t0.ZPOSTIMAGE, t0.ZTIMESTAMP FROM ZPOST t0 WHERE  t0.Z_PK = ? 
CoreData: annotation: sql connection fetch time: 0.0001s
CoreData: annotation: total fetch execution time: 0.0002s for 1 rows.
CoreData: annotation: fault fulfilled from database for : 0x9de26d27ef2a7ac8 <x-coredata://DDA9D961-398D-4C5C-8DAA-919F17139695/Post/p1>
CoreData: sql: BEGIN EXCLUSIVE
CoreData: sql: SELECT Z_MAX FROM Z_PRIMARYKEY WHERE Z_ENT = ?
CoreData: sql: UPDATE OR FAIL Z_PRIMARYKEY SET Z_MAX = ? WHERE Z_ENT = ? AND Z_MAX = ?
CoreData: sql: COMMIT
CoreData: sql: BEGIN EXCLUSIVE
CoreData: sql: INSERT INTO ZSKILLMETADATA(Z_PK, Z_ENT, Z_OPT, ZSKILL, ZDIFFICULTY, ZISACTIVE, ZLATESTUPDATE, ZSECTIONIDENTIFIER, ZTHUMBNAIL) VALUES(?, ?, ?, ?, ?, ?, ?, ?, ?)
CoreData: sql: COMMIT
CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZISVIDEO, t0.ZMEDIAFILENAME, t0.ZNOTES, t0.ZPOSTIMAGE, t0.ZTIMESTAMP FROM ZPOST t0 WHERE   t0.ZNOTES IS NOT NULL 
CoreData: annotation: sql connection fetch time: 0.0001s
CoreData: annotation: total fetch execution time: 0.0002s for 0 rows.
CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZISVIDEO, t0.ZMEDIAFILENAME, t0.ZNOTES, t0.ZPOSTIMAGE, t0.ZTIMESTAMP FROM ZPOST t0 WHERE (  t0.ZISVIDEO IS NOT NULL AND  t0.ZISVIDEO = ?) 
CoreData: annotation: sql connection fetch time: 0.0001s
CoreData: annotation: total fetch execution time: 0.0002s for 1 rows.
CoreData: sql: BEGIN EXCLUSIVE
CoreData: sql: COMMIT
CoreData: sql: BEGIN EXCLUSIVE
CoreData: sql: INSERT INTO ZRECORD(Z_PK, Z_ENT, Z_OPT, ZSKILL, ZRECORDTYPE, ZTIMESTAMP, ZIMAGEFILENAME) VALUES(?, ?, ?, ?, ?, ?, ?)
CoreData: sql: COMMIT
CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZISVIDEO, t0.ZMEDIAFILENAME, t0.ZNOTES, t0.ZPOSTIMAGE, t0.ZTIMESTAMP FROM ZPOST t0 WHERE (  t0.ZISVIDEO IS NOT NULL AND  t0.ZISVIDEO = ?) 
CoreData: annotation: sql connection fetch time: 0.0001s
CoreData: annotation: total fetch execution time: 0.0002s for 0 rows.
CoreData: sql: BEGIN EXCLUSIVE
CoreData: sql: UPDATE OR FAIL ZSKILLMETADATA SET Z_OPT = ?  WHERE Z_PK = ? AND Z_OPT = ?
CoreData: sql: COMMIT
CoreData: sql: SELECT t0.Z_ENT, t0.Z_PK, Z_FOK_2TAGS FROM ZTAG t0 JOIN Z_1TAGS t1 ON t0.Z_PK = t1.Z_2TAGS WHERE t1.Z_1POSTS = ? 
CoreData: annotation: sql connection fetch time: 0.0001s
CoreData: annotation: total fetch execution time: 0.0001s for 1 rows.
CoreData: annotation: to-many relationship fault "tags" for objectID 0x9de26d27ef2a7ac8 <x-coredata://DDA9D961-398D-4C5C-8DAA-919F17139695/Post/p1> fulfilled from database.  Got 1 rows
2020-04-16 10:34:32.587088-0700 SweatNetOffline[33644:4324282] -[NSSymbolicExpression length]: unrecognized selector sent to instance 0x60000315f820
CoreData: annotation: Disconnecting from sqlite database.
CoreData: annotation: Disconnecting from sqlite database.
CoreData: annotation: Disconnecting from sqlite database.
2020-04-16 10:34:32.619490-0700 SweatNetOffline[33644:4324282] *** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '-[NSSymbolicExpression length]: unrecognized selector sent to instance 0x60000315f820'
*** First throw call stack:
(
    0   CoreFoundation                      0x00007fff23c7127e __exceptionPreprocess + 350
    1   libobjc.A.dylib                     0x00007fff513fbb20 objc_exception_throw + 48
    2   CoreFoundation                      0x00007fff23c91fd4 -[NSObject(NSObject) doesNotRecognizeSelector:] + 132
    3   CoreFoundation                      0x00007fff23c75c4c ___forwarding___ + 1436
    4   CoreFoundation                      0x00007fff23c77f78 _CF_forwarding_prep_0 + 120
    5   Foundation                          0x00007fff257159b4 -[NSOrderedSet(NSKeyValueCoding) valueForKeyPath:] + 53
    6   Foundation                          0x00007fff257fea18 -[NSFunctionExpression expressionValueWithObject:context:] + 707
    7   Foundation                          0x00007fff257fe935 -[NSFunctionExpression expressionValueWithObject:context:] + 480
    8   CoreData                            0x00007fff238aa500 -[NSEntityMigrationPolicy createRelationshipsForDestinationInstance:entityMapping:manager:error:] + 1272
    9   CoreData                            0x00007fff238f5a98 -[NSMigrationManager(InternalMethods) _doSecondPassForMapping:error:] + 418
    10  CoreData                            0x00007fff238f6c00 -[NSMigrationManager(InternalMethods) _migrateStoreFromURL:type:options:withMappingModel:toDestinationURL:destinationType:destinationOptions:error:] + 2012
    11  CoreData                            0x00007fff238f3c9f -[NSMigrationManager migrateStoreFromURL:type:options:withMappingModel:toDestinationURL:destinationType:destinationOptions:error:] + 664
    12  CoreData                            0x00007fff239a5eab -[NSStoreMigrationPolicy(InternalMethods) migrateStoreAtURL:toURL:storeType:options:withManager:error:] + 254
    13  CoreData                            0x00007fff239a5466 -[NSStoreMigrationPolicy migrateStoreAtURL:withManager:metadata:options:error:] + 99
    14  CoreData                            0x00007fff239a6adf -[NSStoreMigrationPolicy(InternalMethods) _gatherDataAndPerformMigration:] + 2829
    15  CoreData                            0x00007fff238fc335 __91-[NSPersistentStoreCoordinator addPersistentStoreWithType:configuration:URL:options:error:]_block_invoke + 2469
    16  CoreData                            0x00007fff2390ceb9 gutsOfBlockToNSPersistentStoreCoordinatorPerform + 177
    17  libdispatch.dylib                   0x0000000110c5ed48 _dispatch_client_callout + 8
    18  libdispatch.dylib                   0x0000000110c6d9bf _dispatch_lane_barrier_sync_invoke_and_complete + 132
    19  CoreData                            0x00007fff238f88f9 _perform + 181
    20  CoreData                            0x00007fff237e9334 -[NSPersistentStoreCoordinator addPersistentStoreWithType:configuration:URL:options:error:] + 416
    21  CoreData                            0x00007fff238fb31b -[NSPersistentStoreCoordinator _doAddPersistentStoreWithDescription:privateCopy:completeOnMainThread:withHandler:] + 515
    22  CoreData                            0x00007fff238fb8ab -[NSPersistentStoreCoordinator addPersistentStoreWithDescription:completionHandler:] + 205
    23  CoreData                            0x00007fff238aef63 -[NSPersistentContainer _loadStoreDescriptons:withCompletionHandler:] + 272
    24  CoreData                            0x00007fff238aee2c -[NSPersistentContainer loadPersistentStoresWithCompletionHandler:] + 398
    25  SweatNetOffline                     0x000000010fa9dc05 $s15SweatNetOffline11AppDelegateC19persistentContainerSo012NSPersistentG0CvgAFyXEfU_ + 181
    26  SweatNetOffline                     0x000000010fa9da97 $s15SweatNetOffline11AppDelegateC19persistentContainerSo012NSPersistentG0Cvg + 375
    27  SweatNetOffline                     0x000000010fae8788 $s15SweatNetOffline19Home2ViewControllerC019skillFetchedResultsF033_A1FE4BA766270B7DD28F222CBF923E7DLLSo09NSFetchediF0CyAA13SkillMetaDataCGvgAJyXEfU_ + 360
    28  SweatNetOffline                     0x000000010fae5497 $s15SweatNetOffline19Home2ViewControllerC019skillFetchedResultsF033_A1FE4BA766270B7DD28F222CBF923E7DLLSo09NSFetchediF0CyAA13SkillMetaDataCGvg + 375
    29  SweatNetOffline                     0x000000010fae5771 $s15SweatNetOffline19Home2ViewControllerC11viewDidLoadyyF + 177
    30  SweatNetOffline                     0x000000010fae5c1b $s15SweatNetOffline19Home2ViewControllerC11viewDidLoadyyFTo + 43
    31  UIKitCore                           0x00007fff47a0ef01 -[UIViewController _sendViewDidLoadWithAppearanceProxyObjectTaggingEnabled] + 83
    32  UIKitCore                           0x00007fff47a13e5a -[UIViewController loadViewIfRequired] + 1084
    33  UIKitCore                           0x00007fff479781e4 -[UINavigationController _updateScrollViewFromViewController:toViewController:] + 160
    34  UIKitCore                           0x00007fff479784e8 -[UINavigationController _startTransition:fromViewController:toViewController:] + 144
    35  UIKitCore                           0x00007fff479793b6 -[UINavigationController _startDeferredTransitionIfNeeded:] + 868
    36  UIKitCore                           0x00007fff4797a721 -[UINavigationController __viewWillLayoutSubviews] + 150
    37  UIKitCore                           0x00007fff4795b553 -[UILayoutContainerView layoutSubviews] + 217
    38  UIKitCore                           0x00007fff485784bd -[UIView(CALayerDelegate) layoutSublayersOfLayer:] + 2478
    39  QuartzCore                          0x00007fff2b131db1 -[CALayer layoutSublayers] + 255
    40  QuartzCore                          0x00007fff2b137fa3 _ZN2CA5Layer16layout_if_neededEPNS_11TransactionE + 517
    41  QuartzCore                          0x00007fff2b1438da _ZN2CA5Layer28layout_and_display_if_neededEPNS_11TransactionE + 80
    42  QuartzCore                          0x00007fff2b08a848 _ZN2CA7Context18commit_transactionEPNS_11TransactionEd + 324
    43  QuartzCore                          0x00007fff2b0bfb51 _ZN2CA11Transaction6commitEv + 643
    44  UIKitCore                           0x00007fff480aa575 __34-[UIApplication _firstCommitBlock]_block_invoke_2 + 81
    45  CoreFoundation                      0x00007fff23bd429c __CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__ + 12
    46  CoreFoundation                      0x00007fff23bd3a08 __CFRunLoopDoBlocks + 312
    47  CoreFoundation                      0x00007fff23bce894 __CFRunLoopRun + 1284
    48  CoreFoundation                      0x00007fff23bce066 CFRunLoopRunSpecific + 438
    49  GraphicsServices                    0x00007fff384c0bb0 GSEventRunModal + 65
    50  UIKitCore                           0x00007fff48092d4d UIApplicationMain + 1621
    51  SweatNetOffline                     0x000000010fa9ea7b main + 75
    52  libdyld.dylib                       0x00007fff5227ec25 start + 1
)
libc++abi.dylib: terminating with uncaught exception of type NSException
(lldb)

Solution

Did the migration work? Any way to know if it worked and if this is an issue with my fetch request or if somehow the data was corrupted or if it never worked at all. What is the best way to check this?

I think the migration is still in progress when the exception is thrown. If you look at the call stack, there seem to be migration related calls happening earlier in the stack:

1  ... objc_exception_throw + 48
2  ... [NSObject(NSObject) doesNotRecognizeSelector:] + 132
3  ... ___forwarding___ + 1436
4  ... _CF_forwarding_prep_0 + 120
5  ... [NSOrderedSet(NSKeyValueCoding) valueForKeyPath:] + 53
6  ... [NSFunctionExpression expressionValueWithObject:context:] + 707
7  ... [NSFunctionExpression expressionValueWithObject:context:] + 480
8  ... [NSEntityMigrationPolicy createRelationshipsForDestinationInstance:entityMapping:manager:error:] + 1272
9  ... [NSMigrationManager(InternalMethods) _doSecondPassForMapping:error:] + 418
10 ... [NSMigrationManager(InternalMethods) _migrateStoreFromURL:type:options:withMappingModel:toDestinationURL:destinationType:destinationOptions:error:] + 2012

I wouldn't assume that the migration is completed, just because your viewDidLoad method is called: the migration might be happening asynchronously - it depends on how your CoreData stack is created.

Why are there so many question marks in the SQL - does the mean that the migration is not working properly?

That's just the way the CoreData logs values when you use SQLDebug. They are nothing to be concerned about.

What is Z? all of the attributes seem to start with Z - "WHERE t0.ZNOTES IS NOT NULL" for instance

When CoreData creates the SQLite database, broadly speaking it creates a table for each entity, with columns representing the attributes. The table names and column names are always (at least in my experience) prepended with "Z". So, again, the Zs are no cause for concern.

What is an NSSymbolicExpression? Where would it occur in the core data migration. I understand that somehow its trying to find the length of this object, and the object doesn't have that instance method. Does that mean it is assuming the migration is completed when it hasn't been for instance?

My guess is that you have a pointer mismatch problem in your migration code: a pointer to something like NSString (which does respond to length) is actually pointing to a NSSymbolicExpression object (which doesn't respond to that selector). That might happen if the NSString object is released (and deallocated), and the memory it occupied is subsequently allocated to a NSSymbolicExpression object.

How would I debug this? I would begin by putting a breakpoint in your migration code, and single step through to try to find the offending code. You could also try enabling Zombie tracking (which flags when memory used by deallocated objects is accessed). That's more than I can cover here: some googling should shed some light.