DDLog causing bad Access errors on iOS 7

[NikoRoberts]

Previously working fine on iOS 6.
Latest version through pod update did not help

Exception Type: EXC_BAD_ACCESS Code: KERN_INVALID_ADDRESS at 0x0
10cocoa.lumberjack.ttyLogger Crashed
0    CoreFoundation  CFStringGetCString + 27
1    CoreFoundation  __CFCalendarCreateUCalendar + 158
2    CoreFoundation  __CFCalendarCreateUCalendar + 158
3    CoreFoundation  __CFCalendarSetupCal + 18
4    CoreFoundation  _CFCalendarDecomposeAbsoluteTimeV + 42
5    CoreFoundation  -[__NSCFCalendar components:fromDate:] + 588
6    CoreFoundation  -[_NSCopyOnWriteCalendarWrapper components:fromDate:] + 74
7    education  
DDTTYLogger.m line 1254
-[DDTTYLogger logMessage:]
8    education  
DDLog.m line 629
__16+[DDLog lt_log:]_block_invoke
9    libdispatch.dylib   _dispatch_call_block_and_release + 10
10   libdispatch.dylib   _dispatch_queue_drain$VARIANT$mp + 374
11   libdispatch.dylib   _dispatch_queue_invoke$VARIANT$mp + 42
12   libdispatch.dylib   _dispatch_root_queue_drain + 76
13   libdispatch.dylib   _dispatch_worker_thread2 + 56
14   libsystem_pthread.dylib     _pthread_wqthread + 298

[NikoRoberts]

Version from Podfile.lock : CocoaLumberjack (1.6.2)

Also when running from Xcode for in the iOS7 simulator I get this

[jmah]

I am seeing this also. 👍

[cbowns]

I think I am as well. I'm seeing a mutated collection inside a fast enumeration block, as well as a corrupted object pointer when I log one of my object's properties in a log statement. I'm using a log level macro that expands to use ASYNC_LOG_OBJC_MAYBE.

[cbowns]

Never mind my comment: I had a race condition around data source mutation that, once fixed, made my crashes around the logging macro disappear.

[rootix]

I have the same problem as NikoRoberts

Update: The problem disappeared when i removed the no-arc flag from the files. I did this some hours before due to a arc related error message in Xcode. With ARC enabled, the problem does not longer occur and the logging is working.

[NikoRoberts]

just to let everyone know we use 1.6.2 and it is already using ARC and it still crashes

[cbowns]

@NikoRoberts can you share more information about what you're doing with the framework when it crashes: can you post a code snippet around the crashing callsite? Also, a full crash log will help. If you're seeing this crash reliably, is it always on the same line, or does it vary a bit? (If the latter, every different crash log will shed a bit more light on it.)

[bpoplauschi]

@NikoRoberts any updates on this, I use the latest version on several projects and never got this crash. It would help a lot if you could provide some extra info.

[NikoRoberts]

Status
We have removed Lumberjack and rolled our own since it just throws errors for us.

Info We Have

cocoa.lumberjack.ttyLogger Crashed
0    libobjc.A.dylib     objc_msgSend + 5
1    CoreFoundation  -[_NSCopyOnWriteCalendarWrapper components:fromDate:] + 74
2    eventapp   
DDTTYLogger.m line 1255
-[DDTTYLogger logMessage:]
3    eventapp   
DDLog.m line 628
__16+[DDLog lt_log:]_block_invoke
4 ...    libdispatch.dylib   _dispatch_call_block_and_release + 10
9    libsystem_pthread.dylib     _pthread_wqthread + 298

We were just doing DDLog calls in various places in the app in various contexts from multiple threads.
I can't find out what the code was that pushed that asynchronous request because it doesn't appear in logs.

[bpoplauschi]

We'll look into this and hopefully fix it. Sorry to hear you had to drop Lumberjack.

[NikoRoberts]

We will pick it back up again if you can figure out how to debug it or patch it.
If we can help, just tell us.
@vascoorey @janjokela

[cbowns]

@NikoRoberts I'm happy to help debug this if you want to try re-integrating it in one place you know it's broken.

[bpoplauschi]

@NikoRoberts @cbowns after a short code review, I can assume the crash is due to DDTTYLogger.m logMessage

NSDateComponents *components = [calendar components:calendarUnitFlags fromDate:logMessage->timestamp];

NSCalendar is thread-unsafe, so probably this line is getting called from 2 threads at the same time.

I am trying to reproduce the issue and patch it so we can release 1.6.3

[NikoRoberts]

Ah thanks for this guys. Sorry we couldn't help you out more. We are just
neck deep in our own to-do lists

Glad you figured it out though. We will probably swap Lumberjack back in
again when you release 1.6.3 :)

--
Niko Roberts
Managing Director @ Tasboa
tel: (+351) 962 955 325 | web: www.tasboa.com | linkedIn:
nikoroberts http://pt.linkedin.com/in/nikoroberts

This email and any files transmitted with it are confidential and intended
solely for the use of the individual or entity to whom they are addressed.
If you are not the intended recipient you are notified that disclosing,
copying, distributing or taking any action in reliance on the contents of
this information is strictly prohibited.

On 7 November 2013 11:17, Bogdan Poplauschi notifications@github.comwrote:

@NikoRoberts https://github.com/NikoRoberts @cbownshttps://github.com/cbownsafter a short code review, I can assume the crash is due to
DDTTYLogger.m logMessage

NSDateComponents *components = [calendar components:calendarUnitFlags fromDate:logMessage->timestamp];

NSCalendar is thread-unsafehttps://developer.apple.com/library/mac/documentation/cocoa/conceptual/Multithreading/ThreadSafetySummary/ThreadSafetySummary.html,
so probably this line is getting called from 2 threads at the same time.

I am trying to reproduce the issue and patch it so we can release 1.6.3

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/140#issuecomment-27951324
.

[bpoplauschi]

This crash is very strange. I tried creating 100 threads that access NSCalendar components:fromDate: at the same time on the same NSCalendar instance, never got a crash (simulator 7, simulator 6.1, device 7). More than that, logMessage should be called from the DDTTYLogger queue which is a serial queue. @rivera-ernesto any ideas? I'm kind of blocked

[cbowns]

Having seen a similar crash that turned out to be my own fault, here's some background on what I saw: DDLog was being called in a loop running on a mutating collection, and sometimes the collection would be mutated on another thread while logging was being executed. This may simply be a latent bug being exposed by Lumberjack, not a Lumberjack bug in its own right.

[rivera-ernesto]

As some of the recent pull request may have fixed the original reporter's issue (although we can't know as he's no longer using the library), and also as most participants here have fixed their crashes, I'll close this issue for the 1.6.3 release.

Feel free to reopen it later if needed.

[rickyzhang82]

@bpoplauschi I experienced the same issues when using commit 79f6d2a. The thread has EXC_BAD_ACCESS error.

It stopped at DDTTYLogger.m when calculating timestamp

[NikoRoberts]

now I think we have a little window in the coming weeks where we can test a reintegration of Lumberjack into the project. If @janjokela or @vascoorey find anything I am sure we will post it here

[bpoplauschi]

@NikoRoberts @janjokela @vascoorey any updates here?

[rivera-ernesto]

Closing this one once again until it resurfaces...

[ZehCastro]

I got the same error at the same place as NikoRoberts: NSDateComponents *components = [calendar components:calendarUnitFlags fromDate:logMessage->timestamp];
In my case it seems connected to a call to [NSTimeZone setDefaultTimeZone: aTimeZone];
Everything works if I comment that line setting the timezone.

I'm using this version

[ZehCastro]

Changing this line:

NSDateComponents *components = [calendar components:calendarUnitFlags fromDate:logMessage->timestamp];

With this:

NSDateComponents* components = [[NSCalendar autoupdatingCurrentCalendar] components:calendarUnitFlags fromDate:logMessage->timestamp];

Seems to have stopped the crashes for me.

[rivera-ernesto]

Could you pull request that?

[rivera-ernesto]

Please check again with the latest master (pod 'CocoaLumberjack', :head).