[Home]

Summary:ASTERISK-18138: lock.c:280 __ast_pthread_mutex_lock: ccss.c line 3478 (ast_cc_offer): Error obtaining mutex: Invalid argument
Reporter:Marcello Ceschia (marcelloceschia)Labels:
Date Opened:2011-07-14 11:00:49Date Closed:2011-09-22 07:14:14
Priority:MajorRegression?
Status:Closed/CompleteComponents:Core/CallCompletionSupplementaryServices
Versions:1.8.5.0 Frequency of
Occurrence		One Time
Related
Issues:
Environment:Attachments:
Description:after IAX call:

-- Hungup 'IAX2/server123-3511'
[2011-07-14 17:51:10] ERROR[7598]: lock.c:280 __ast_pthread_mutex_lock: ccss.c line 3478 (ast_cc_offer): Error obtaining mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: lock.c:407 __ast_pthread_mutex_unlock: ccss.c line 3480 (ast_cc_offer): mutex 'caller_chan' freed more times than we've locked!
[2011-07-14 17:51:10] ERROR[7598]: lock.c:438 __ast_pthread_mutex_unlock: ccss.c line 3480 (ast_cc_offer): Error releasing mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: astobj2.c:258 internal_ao2_ref: refcount -1 on object 0xff0e498
[2011-07-14 17:51:10] ERROR[7598]: lock.c:280 __ast_pthread_mutex_lock: cel.c line 482 (ast_cel_report_event): Error obtaining mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: lock.c:407 __ast_pthread_mutex_unlock: cel.c line 487 (ast_cel_report_event): mutex 'chan' freed more times than we've locked!
[2011-07-14 17:51:10] ERROR[7598]: lock.c:438 __ast_pthread_mutex_unlock: cel.c line 487 (ast_cel_report_event): Error releasing mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: lock.c:280 __ast_pthread_mutex_lock: channel.c line 2376 (ast_channel_destructor): Error obtaining mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: lock.c:407 __ast_pthread_mutex_unlock: channel.c line 2380 (ast_channel_destructor): mutex 'chan' freed more times than we've locked!
[2011-07-14 17:51:10] ERROR[7598]: lock.c:438 __ast_pthread_mutex_unlock: channel.c line 2380 (ast_channel_destructor): Error releasing mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: lock.c:280 __ast_pthread_mutex_lock: channel.c line 2384 (ast_channel_destructor): Error obtaining mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: lock.c:407 __ast_pthread_mutex_unlock: channel.c line 2385 (ast_channel_destructor): mutex 'chan' freed more times than we've locked!
[2011-07-14 17:51:10] ERROR[7598]: lock.c:438 __ast_pthread_mutex_unlock: channel.c line 2385 (ast_channel_destructor): Error releasing mutex: Invalid argument
[2011-07-14 17:51:10] ERROR[7598]: res_timing_timerfd.c:124 timerfd_timer_close: Couldn't find timer with handle 52
[2011-07-14 17:51:10] ERROR[7598]: lock.c:113 __ast_pthread_mutex_destroy: astobj2.c line 265 (internal_ao2_ref): Error: attempt to destroy invalid mutex '&obj->priv_data.lock'.



Comments:By: Russell Bryant (russell) 2011-07-26 10:44:40.548-0500

Thank you for your bug report. In order to move your issue forward, we require a backtrace[1] from the core file produced after the crash. Also, be sure you have DONT_OPTIMIZE enabled in menuselect within the Compiler Flags section, then:

make install

After enabling, reproduce the crash, and then execute the backtrace[1] instructions. When complete, attach that file to this issue report.

[1] https://wiki.asterisk.org/wiki/display/AST/Getting+a+Backtrace


By: David Woolley (davidw) 2011-07-26 11:09:50.086-0500

In my experience, if you get this sort of error message, the final crash is the result of memory corruption and happens sufficiently after the primary error that the backtrace contributes very little of any use.  The locking failure messages are usually much more useful.

Also my experience is that this sort of failure can take months to reproduce,even on a loaded system, and can only really be reproduced on a test system by modifying the code to exagerate delays.

The only other approach I've found to debugging these is to breakpoint the error message generation, so that one gets a backtrace sufficiently close to the primary fault.  That still requires that you can reproduce the fault with reasonable frequency.
By: Leif Madsen (lmadsen) 2011-09-22 07:14:14.039-0500

I'm closing this issue due to lack of feedback. I'm seeing the use of res_timing_timerfd on the console output as well. I'd suggest using res_timing_dahdi or trying res_timing_timerfd after 1.8.7.0-rc1.