semaphore_wait_trap : failed to resume in time #53

Closed
sgadhvi opened this Issue Aug 21, 2012 · 13 comments

Comments

Projects
None yet
8 participants
@sgadhvi

sgadhvi commented Aug 21, 2012

I get the below error while resuming the application there is some code in on resume which does the loging. but after showing splash screen app crashes with below logs.
What could be going wrong?

0 libsystem_kernel.dylib 0x306eb060 semaphore_wait_trap + 8
1 libdispatch.dylib 0x33879472 _dispatch_group_wait_slow + 146
2 libdispatch.dylib 0x338793d2 dispatch_group_wait$VARIANT$mp + 22
3 XXXX 0x0012d38c +DDLog lt_log:
4 XXXX 0x0012c824 __+[DDLog queueLogMessage:asynchronously:]_block_invoke_1 (DDLog.m:476)
5 libdispatch.dylib 0x338778c8 _dispatch_barrier_sync_f_invoke + 20
6 libdispatch.dylib 0x33877728 dispatch_barrier_sync_f$VARIANT$mp + 56
7 libdispatch.dylib 0x33877348 dispatch_sync_f$VARIANT$mp + 12
8 libdispatch.dylib 0x338779f2 dispatch_sync$VARIANT$mp + 26
9 XXXX 0x0012c7d0 +DDLog queueLogMessage:asynchronously:
10 XXXX 0x0012ca8a +DDLog log:level:flag:context:file:function:line:withTag:format:

@sguillope

This comment has been minimized.

Show comment Hide comment
@sguillope

sguillope Nov 6, 2012

Contributor

We're having the same issue. App just hangs on this semaphore_wait_trap ()

#0  0x9ca2bc5e in semaphore_wait_trap ()
#1  0x01e9aea4 in _dispatch_group_wait_slow ()
#2  0x01e9afb0 in dispatch_group_wait ()
#3  0x00019fa0 in +[DDLog lt_log:] at DDLog.m:658
#4  0x00018ea0 in __40+[DDLog queueLogMessage:asynchronously:]_block_invoke_0 at DDLog.m:285
#5  0x01e99951 in _dispatch_barrier_sync_f_invoke ()
#6  0x01e99e00 in dispatch_barrier_sync_f ()
#7  0x01e99f80 in dispatch_sync ()
#8  0x00018e59 in +[DDLog queueLogMessage:asynchronously:] at DDLog.m:291
#9  0x00019008 in +[DDLog log:level:flag:context:file:function:line:tag:format:] at DDLog.m:320
#10 0x00027661 in -[BaseService objectLoader:didFailWithError:] at BaseService.m:177
#11 0x000bd59f in -[RKObjectLoader informDelegateOfError:] at RestKit/Code/ObjectMapping/RKObjectLoader.m:117
#12 0x000bebc5 in -[RKObjectLoader isResponseMappable] at RestKit/Code/ObjectMapping/RKObjectLoader.m:334
#13 0x000a12fe in -[RKManagedObjectLoader isResponseMappable] at RestKit/Code/CoreData/RKManagedObjectLoader.m:235
#14 0x000bf895 in -[RKObjectLoader didFinishLoad:] at RestKit/Code/ObjectMapping/RKObjectLoader.m:469
#15 0x000ba705 in -[RKResponse connectionDidFinishLoading:] at RestKit/Code/Network/RKResponse.m:232
#16 0x0173ba49 in ___NSURLConnectionDidFinishLoading_block_invoke_0 ()
#17 0x01739e84 in __65-[NSURLConnectionInternal _withConnectionAndDelegate:onlyActive:]_block_invoke_0 ()
#18 0x0173aea7 in -[NSURLConnectionInternalConnection invokeForDelegate:] ()
#19 0x01739e3f in -[NSURLConnectionInternal _withConnectionAndDelegate:onlyActive:] ()
#20 0x01739fc5 in -[NSURLConnectionInternal _withActiveConnectionAndDelegate:] ()
#21 0x0167ef5a in _NSURLConnectionDidFinishLoading ()
#22 0x007d9a39 in URLConnectionClient::_clientDidFinishLoading(URLConnectionClient::ClientConnectionEventQueue*) ()
#23 0x008a6596 in URLConnectionClient::ClientConnectionEventQueue::processAllEventsAndConsumePayload(XConnectionEventInfo<XClientEvent, XClientEventParams>*, long) ()
#24 0x008a6861 in URLConnectionClient::ClientConnectionEventQueue::processAllEventsAndConsumePayload(XConnectionEventInfo<XClientEvent, XClientEventParams>*, long) ()
#25 0x007d0120 in URLConnectionClient::processEvents() ()
#26 0x008a6117 in non-virtual thunk to URLConnectionInstanceData::multiplexerClientPerform() ()
#27 0x007cffbf in MultiplexerSource::perform() ()
#28 0x0202a94f in __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ ()
#29 0x01f8db43 in __CFRunLoopDoSources0 ()
#30 0x01f8d424 in __CFRunLoopRun ()
#31 0x01f8cd84 in CFRunLoopRunSpecific ()
#32 0x01f8cc9b in CFRunLoopRunInMode ()
#33 0x026c47d8 in GSEventRunModal ()
#34 0x026c488a in GSEventRun ()
#35 0x00a59626 in UIApplicationMain ()
#36 0x0000335a in main at main.m:16
#37 0x000020d5 in start ()
Contributor

sguillope commented Nov 6, 2012

We're having the same issue. App just hangs on this semaphore_wait_trap ()

#0  0x9ca2bc5e in semaphore_wait_trap ()
#1  0x01e9aea4 in _dispatch_group_wait_slow ()
#2  0x01e9afb0 in dispatch_group_wait ()
#3  0x00019fa0 in +[DDLog lt_log:] at DDLog.m:658
#4  0x00018ea0 in __40+[DDLog queueLogMessage:asynchronously:]_block_invoke_0 at DDLog.m:285
#5  0x01e99951 in _dispatch_barrier_sync_f_invoke ()
#6  0x01e99e00 in dispatch_barrier_sync_f ()
#7  0x01e99f80 in dispatch_sync ()
#8  0x00018e59 in +[DDLog queueLogMessage:asynchronously:] at DDLog.m:291
#9  0x00019008 in +[DDLog log:level:flag:context:file:function:line:tag:format:] at DDLog.m:320
#10 0x00027661 in -[BaseService objectLoader:didFailWithError:] at BaseService.m:177
#11 0x000bd59f in -[RKObjectLoader informDelegateOfError:] at RestKit/Code/ObjectMapping/RKObjectLoader.m:117
#12 0x000bebc5 in -[RKObjectLoader isResponseMappable] at RestKit/Code/ObjectMapping/RKObjectLoader.m:334
#13 0x000a12fe in -[RKManagedObjectLoader isResponseMappable] at RestKit/Code/CoreData/RKManagedObjectLoader.m:235
#14 0x000bf895 in -[RKObjectLoader didFinishLoad:] at RestKit/Code/ObjectMapping/RKObjectLoader.m:469
#15 0x000ba705 in -[RKResponse connectionDidFinishLoading:] at RestKit/Code/Network/RKResponse.m:232
#16 0x0173ba49 in ___NSURLConnectionDidFinishLoading_block_invoke_0 ()
#17 0x01739e84 in __65-[NSURLConnectionInternal _withConnectionAndDelegate:onlyActive:]_block_invoke_0 ()
#18 0x0173aea7 in -[NSURLConnectionInternalConnection invokeForDelegate:] ()
#19 0x01739e3f in -[NSURLConnectionInternal _withConnectionAndDelegate:onlyActive:] ()
#20 0x01739fc5 in -[NSURLConnectionInternal _withActiveConnectionAndDelegate:] ()
#21 0x0167ef5a in _NSURLConnectionDidFinishLoading ()
#22 0x007d9a39 in URLConnectionClient::_clientDidFinishLoading(URLConnectionClient::ClientConnectionEventQueue*) ()
#23 0x008a6596 in URLConnectionClient::ClientConnectionEventQueue::processAllEventsAndConsumePayload(XConnectionEventInfo<XClientEvent, XClientEventParams>*, long) ()
#24 0x008a6861 in URLConnectionClient::ClientConnectionEventQueue::processAllEventsAndConsumePayload(XConnectionEventInfo<XClientEvent, XClientEventParams>*, long) ()
#25 0x007d0120 in URLConnectionClient::processEvents() ()
#26 0x008a6117 in non-virtual thunk to URLConnectionInstanceData::multiplexerClientPerform() ()
#27 0x007cffbf in MultiplexerSource::perform() ()
#28 0x0202a94f in __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ ()
#29 0x01f8db43 in __CFRunLoopDoSources0 ()
#30 0x01f8d424 in __CFRunLoopRun ()
#31 0x01f8cd84 in CFRunLoopRunSpecific ()
#32 0x01f8cc9b in CFRunLoopRunInMode ()
#33 0x026c47d8 in GSEventRunModal ()
#34 0x026c488a in GSEventRun ()
#35 0x00a59626 in UIApplicationMain ()
#36 0x0000335a in main at main.m:16
#37 0x000020d5 in start ()
@robbiehanson

This comment has been minimized.

Show comment Hide comment
@robbiehanson

robbiehanson Apr 2, 2013

Contributor

There are a couple possibilities. Are you using any custom loggers which may be running slow?

Contributor

robbiehanson commented Apr 2, 2013

There are a couple possibilities. Are you using any custom loggers which may be running slow?

@sguillope

This comment has been minimized.

Show comment Hide comment
@sguillope

sguillope Apr 2, 2013

Contributor

Yes we were using one at the time.
Here's the code:

@implementation LogFormatter
{
  NSDateFormatter *_dateFormatter;
}

- (id)init
{
  self = [super init];
  if (self)
  {
    _dateFormatter = [[NSDateFormatter alloc] init];
    [_dateFormatter setFormatterBehavior:NSDateFormatterBehavior10_4];
    [_dateFormatter setDateFormat:@"yyyy-MM-dd HH:mm:ss:SSS"];
  }
  return self;
}

- (NSString *)formatLogMessage:(DDLogMessage *)logMessage
{
  NSString *logLevel;
  switch (logMessage->logFlag)
  {
    case LOG_FLAG_ERROR : logLevel = @"E"; break;
    case LOG_FLAG_WARN  : logLevel = @"W"; break;
    case LOG_FLAG_INFO  : logLevel = @"I"; break;
    default             : logLevel = @"V"; break;
  }

  NSString *dateAndTime = [_dateFormatter stringFromDate:(logMessage->timestamp)];

  return [NSString stringWithFormat:@"[%@] %@ [%@.m:%d] %@\n%@", dateAndTime, logLevel, logMessage.fileName, logMessage->lineNumber, logMessage.methodName, logMessage->logMsg];
}

@end
Contributor

sguillope commented Apr 2, 2013

Yes we were using one at the time.
Here's the code:

@implementation LogFormatter
{
  NSDateFormatter *_dateFormatter;
}

- (id)init
{
  self = [super init];
  if (self)
  {
    _dateFormatter = [[NSDateFormatter alloc] init];
    [_dateFormatter setFormatterBehavior:NSDateFormatterBehavior10_4];
    [_dateFormatter setDateFormat:@"yyyy-MM-dd HH:mm:ss:SSS"];
  }
  return self;
}

- (NSString *)formatLogMessage:(DDLogMessage *)logMessage
{
  NSString *logLevel;
  switch (logMessage->logFlag)
  {
    case LOG_FLAG_ERROR : logLevel = @"E"; break;
    case LOG_FLAG_WARN  : logLevel = @"W"; break;
    case LOG_FLAG_INFO  : logLevel = @"I"; break;
    default             : logLevel = @"V"; break;
  }

  NSString *dateAndTime = [_dateFormatter stringFromDate:(logMessage->timestamp)];

  return [NSString stringWithFormat:@"[%@] %@ [%@.m:%d] %@\n%@", dateAndTime, logLevel, logMessage.fileName, logMessage->lineNumber, logMessage.methodName, logMessage->logMsg];
}

@end
@robbiehanson

This comment has been minimized.

Show comment Hide comment
@robbiehanson

robbiehanson Apr 2, 2013

Contributor

This is a formatter. Were you using any custom loggers? Loggers are the components that take the (possibly formatted) log message and do something with it (such as writing to console or file). Examples of loggers are DDFileLogger, DDTTYLogger, etc.

I'm asking because I've seen situations in which one writes a custom logger which performs rather slowly. For example, a custom logger that uses a database, and does a transaction for each log message. The database can only handle a few transactions per second, but the application is generating dozens of log messages per second. Eventually the system gets backed up.

(The above example can be fixed by using an architecture similar to that in DDAbstractDatabaseLogger, where log messages are queued, and flushed to the database in batches.)

Contributor

robbiehanson commented Apr 2, 2013

This is a formatter. Were you using any custom loggers? Loggers are the components that take the (possibly formatted) log message and do something with it (such as writing to console or file). Examples of loggers are DDFileLogger, DDTTYLogger, etc.

I'm asking because I've seen situations in which one writes a custom logger which performs rather slowly. For example, a custom logger that uses a database, and does a transaction for each log message. The database can only handle a few transactions per second, but the application is generating dozens of log messages per second. Eventually the system gets backed up.

(The above example can be fixed by using an architecture similar to that in DDAbstractDatabaseLogger, where log messages are queued, and flushed to the database in batches.)

@sguillope

This comment has been minimized.

Show comment Hide comment
@sguillope

sguillope Apr 2, 2013

Contributor

Oops sorry I didn't read that right.
We don't use a custom logger.

Here's the code that does the configuration:

  LogFormatter *ASLLogFormatter = [[LogFormatter alloc] init];

  // DDLog configuration
  [[DDASLLogger sharedInstance] setLogFormatter:ASLLogFormatter];
  [DDLog addLogger:[DDASLLogger sharedInstance]];
#ifdef DEBUG
  LogFormatter *TTYLogFormatter = [[LogFormatter alloc] init];
  [[DDTTYLogger sharedInstance] setLogFormatter:TTYLogFormatter];
  [DDLog addLogger:[DDTTYLogger sharedInstance]];
#endif

Also some macros defined like this:

#define RESTClientLogError(frmt, ...)     SYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_ERROR,   LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
#define RESTClientLogWarn(frmt, ...)     ASYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_WARN,    LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
#define RESTClientLogInfo(frmt, ...)     ASYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_INFO,    LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
#define RESTClientLogVerbose(frmt, ...)  ASYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_VERBOSE, LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
Contributor

sguillope commented Apr 2, 2013

Oops sorry I didn't read that right.
We don't use a custom logger.

Here's the code that does the configuration:

  LogFormatter *ASLLogFormatter = [[LogFormatter alloc] init];

  // DDLog configuration
  [[DDASLLogger sharedInstance] setLogFormatter:ASLLogFormatter];
  [DDLog addLogger:[DDASLLogger sharedInstance]];
#ifdef DEBUG
  LogFormatter *TTYLogFormatter = [[LogFormatter alloc] init];
  [[DDTTYLogger sharedInstance] setLogFormatter:TTYLogFormatter];
  [DDLog addLogger:[DDTTYLogger sharedInstance]];
#endif

Also some macros defined like this:

#define RESTClientLogError(frmt, ...)     SYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_ERROR,   LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
#define RESTClientLogWarn(frmt, ...)     ASYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_WARN,    LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
#define RESTClientLogInfo(frmt, ...)     ASYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_INFO,    LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
#define RESTClientLogVerbose(frmt, ...)  ASYNC_LOG_OBJC_MAYBE(restClientLogLevel, LOG_FLAG_VERBOSE, LOG_CONTEXT_REST_CLIENT, frmt, ##__VA_ARGS__)
@bpoplauschi

This comment has been minimized.

Show comment Hide comment
@bpoplauschi

bpoplauschi Nov 1, 2013

Member

@sgadhvi , @sguillope does this issue still reproduce? Do you have any updates/extra info on this?

Member

bpoplauschi commented Nov 1, 2013

@sgadhvi , @sguillope does this issue still reproduce? Do you have any updates/extra info on this?

@rivera-ernesto

This comment has been minimized.

Show comment Hide comment
@rivera-ernesto

rivera-ernesto Nov 5, 2013

Member

I think we should close it for now. If the problem persistes we can update the info and reopen it.

Member

rivera-ernesto commented Nov 5, 2013

I think we should close it for now. If the problem persistes we can update the info and reopen it.

@BlackBears

This comment has been minimized.

Show comment Hide comment
@BlackBears

BlackBears Apr 1, 2014

Contributor

I have a very similar issue for which the issue should be reopened. Similar to the OP, I have code that takes care of maintenance tasks when the application resumes. Most of said work is done in a background queue. The app regularly freezes on resuming from background:

screen shot 2014-04-01 at 6 00 34 am

I use no custom loggers.

Contributor

BlackBears commented Apr 1, 2014

I have a very similar issue for which the issue should be reopened. Similar to the OP, I have code that takes care of maintenance tasks when the application resumes. Most of said work is done in a background queue. The app regularly freezes on resuming from background:

screen shot 2014-04-01 at 6 00 34 am

I use no custom loggers.

@bpoplauschi bpoplauschi reopened this Apr 1, 2014

@bpoplauschi

This comment has been minimized.

Show comment Hide comment
@bpoplauschi

bpoplauschi Apr 1, 2014

Member

reopened based on the previous comment

Member

bpoplauschi commented Apr 1, 2014

reopened based on the previous comment

@Whirlwind

This comment has been minimized.

Show comment Hide comment
@Whirlwind

Whirlwind Nov 19, 2014

I have same problem, and I just use ASL and TTY logger.

I have same problem, and I just use ASL and TTY logger.

@Autoc0diq

This comment has been minimized.

Show comment Hide comment
@Autoc0diq

Autoc0diq Dec 23, 2014

Contributor

Same here on iOS 8.1

Contributor

Autoc0diq commented Dec 23, 2014

Same here on iOS 8.1

@rivera-ernesto

This comment has been minimized.

Show comment Hide comment
@rivera-ernesto

rivera-ernesto Feb 17, 2015

Member

Can someone share a simple project that reproduces the bug?

Member

rivera-ernesto commented Feb 17, 2015

Can someone share a simple project that reproduces the bug?

@bpoplauschi

This comment has been minimized.

Show comment Hide comment
@bpoplauschi

bpoplauschi Oct 23, 2015

Member

Closing, due to lack of response. Please comment and we can reopen it if you can provide a simple demo project.

Member

bpoplauschi commented Oct 23, 2015

Closing, due to lack of response. Please comment and we can reopen it if you can provide a simple demo project.

@0xced 0xced referenced this issue Jan 23, 2018

Merged

Fix locking the main thread #911

7 of 8 tasks complete
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment