ThreadSanitizer detects data race when initializing FirebaseApp instance

[pot8os]

• Xcode version: 9.3.1
• Firebase SDK version: 5.0.1
• Firebase Component: Probably Analytics has an issue, I guess.

Hello,

After I upgraded Firebase components to 5.0.1 from 4.13.0, my app stops and the thread sanitizer shows the following stack trace while I'm running on the Xcode.

==================
WARNING: ThreadSanitizer: data race (pid=5024)
  Read of size 1 at 0x00010c745a81 by main thread (mutexes: write M821):
    #0 FIRLogBasic <null> (MyApp:x86_64+0x100467a76)
    #1 -[FIRInstanceIDLogger logFuncDebug:messageCode:msg:] <null> (MyApp:x86_64+0x1004a11d7)
    #2 +[FIRApp configureDefaultAppWithOptions:sendingNotifications:] <null> (MyApp:x86_64+0x10045a133)
    #3 +[FIRApp configureWithOptions:] <null> (MyApp:x86_64+0x100459c53)
    #4 _T07MyApp11AppDelegateC11applicationSbSo13UIApplicationC_s10DictionaryVySC0F16LaunchOptionsKeyVypGSg022didFinishLaunchingWithI0tF AppDelegate.swift:109 (MyApp:x86_64+0x10005568b)
    #5 _T07MyApp11AppDelegateC11applicationSbSo13UIApplicationC_s10DictionaryVySC0F16LaunchOptionsKeyVypGSg022didFinishLaunchingWithI0tFTo AppDelegate.swift (MyApp:x86_64+0x100055bba)
    #6 -[UIApplication _handleDelegateCallbacksWithOptions:isSuspended:restoreState:] <null> (UIKit:x86_64+0x2175a)
    #7 start <null> (libdyld.dylib:x86_64+0x1954)

  Previous write of size 1 at 0x00010c745a81 by thread T12:
    #0 __FIRSetAnalyticsDebugMode_block_invoke <null> (MyApp:x86_64+0x100466dfc)
    #1 __tsan::invoke_and_release_block(void*) <null> (libclang_rt.tsan_iossim_dynamic.dylib:x86_64+0x622bb)
    #2 _dispatch_client_callout <null> (libdispatch.dylib:x86_64+0x3847)

  Location is global 'sFIRAnalyticsDebugMode' at 0x00010c745a81 (MyApp+0x0001009a6a81)

  Mutex M821 (0x7b1800005418) created at:
    #0 pthread_mutex_lock <null> (libclang_rt.tsan_iossim_dynamic.dylib:x86_64+0x35b2e)
    #1 recursive_mutex_tt<false>::lock() <null> (libobjc.A.dylib:x86_64+0xf81c)
    #2 start <null> (libdyld.dylib:x86_64+0x1954)

  Thread T12 (tid=2580300, running) is a GCD worker thread

SUMMARY: ThreadSanitizer: data race (MyApp:x86_64+0x100467a76) in FIRLogBasic
==================

I'm sure it doesn't exist when I use 4.13.0.

Steps to reproduce:

In my AppDelegate.swift, it initializes FirebaseApp like this. I think it's very normal.

// Firebase Debug
guard
  let filePath = Bundle.main.path(forResource: "GoogleService-Info-Debug", ofType: "plist"),
  let options = FirebaseOptions(contentsOfFile: filePath) 
  else { fatalError() }
FirebaseApp.configure(options: options) // Breakpoint stops here

I'm using the following components;

• Firebase 5.0.1
• FirebaseABTesting 2.0.0
• FirebaseAnalytics 5.0.0
• FirebaseCore 5.0.1
• FirebaseInstanceID 3.0.0
• FirebaseMessaging 3.0.0
• FirebaseRemoteConfig 3.0.0

Thanks.

[wilhuff]

@davidair I think this is the intentional race around the log level and analytics debug mode. Short of making these values atomics, one possible way to handle this would be to annotate things with __attribute__((no_sanitize("thread"))).

@pot8os I believe you can work around this util we release a fix by adding the offending function to a blacklist.

Create a file blacklist.txt:

fun:FIRLogBasic

Then add to your OTHER_CFLAGS -fsanitize-blacklist blacklist.txt

[davidair]

I think adding the no_sanitize attribute is a reasonable approach

[pot8os]

@wilhuff Thanks for your explanations. Unfortunately, it didn't work the workaround you suggested. And I'm not sure how I find out what it's wrong.
It'd be helpful if you could try to see if it works in your environment when you have time.

What I did:

• Add blacklist.txt

Content is

fun:*FIR*

(I also tried fun:FIRLogBasic but it also didn't work and I thought it seems not enough according to stacktrace)

• Update OTHER_CFLAGS like this

Thanks.

[paulb777]

I saw a different thread sanitizer test case and fixed that one. I'm not able to reproduce one in FIRLogBasic. Let me know if it still occurs with the fix in #1390 and we can reopen.

[FrankB1708]

I'm using a current version 5.4.0 and I'm seeing a very similar pattern:
WARNING: ThreadSanitizer: data race (pid=21644)
Write of size 1 at 0x00010c4f5091 by thread T6:
#0 __FIRSetAnalyticsDebugMode_block_invoke :3746336 (TunesGenie:x86_64+0x100302071)
#1 __tsan::invoke_and_release_block(void*) :3746336 (libclang_rt.tsan_iossim_dynamic.dylib:x86_64+0x622bb)
#2 _dispatch_client_callout :3746336 (libdispatch.dylib:x86_64+0x3708)

Previous read of size 1 at 0x00010c4f5091 by main thread (mutexes: write M22653341146430552):
#0 FIRLogBasic :3746336 (TunesGenie:x86_64+0x100302985)
#1 FIRLogDebug :3746336 (TunesGenie:x86_64+0x1003041df)
#2 +[FIRApp configureDefaultAppWithOptions:sendingNotifications:] :3746336 (TunesGenie:x86_64+0x1002f5c67)
#3 +[FIRApp configureWithOptions:] :3746336 (TunesGenie:x86_64+0x1002f5a90)
#4 _T0So11FirebaseAppC10TunesGenieE9configureyAC0A15OptionsProtocol_p7options_tFZ FirebaseAppExtension.swift:21 (TunesGenie:x86_64+0x10014d14f)
#5 _T0So11FirebaseAppC10TunesGenie0aB8ProtocolA2cDP9configureyAC0a7OptionsE0_p7options_tFZTW FirebaseAppExtension.swift (TunesGenie:x86_64+0x10014d2da)
#6 _T010TunesGenie27FirebaseAppInterfaceGenericC13configureOnce33_DFD06E20D4C27AC94D334043E113908DLLyyF FirebaseAppInterfaceGeneric.swift:143 (TunesGenie:x86_64+0x10008b81f)
#7 T010TunesGenie27FirebaseAppInterfaceGenericC10_configure33_DFD06E20D4C27AC94D334043E113908DLLyyFyycfU FirebaseAppInterfaceGeneric.swift:81 (TunesGenie:x86_64+0x1000899b5)
#8 _T010TunesGenie27FirebaseAppInterfaceGenericC10_configure33_DFD06E20D4C27AC94D334043E113908DLLyyFyycfU_TA FirebaseAppInterfaceGeneric.swift (TunesGenie:x86_64+0x100089a6d)
#9 _T0Ig_IyB_TR UserNotificationManager.swift (TunesGenie:x86_64+0x10000b000)
#10 __tsan::invoke_and_release_block(void*) :3746336 (libclang_rt.tsan_iossim_dynamic.dylib:x86_64+0x622bb)
#11 _dispatch_client_callout :3746336 (libdispatch.dylib:x86_64+0x3708)
#12 +[XCTRunnerDaemonSession sharedSession] :3746336 (XCTest:x86_64+0x83afd)
#13 start :3746336 (libdyld.dylib:x86_64+0x1954)

Location is global 'sFIRAnalyticsDebugMode' at 0x00010c4f5091 (TunesGenie+0x000100812091)

Mutex M22653341146430552 is already destroyed.

Thread T6 (tid=435761, running) is a GCD worker thread

SUMMARY: ThreadSanitizer: data race (TunesGenie:x86_64+0x100302071) in __FIRSetAnalyticsDebugMode_block_invoke

[paulb777]

@FrankB1708 The FIRSetAnalyticsDebugMode tsan issue is planned to be fixed in the next release. It's part of #1370