Error releasing mutex: Operation not permitted

Trixbox 2.8.0.4
A400P and G400P

Both inbound and outbound calls on G400P seem to work okay for now, however i am worried about the last lines.

[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h538 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): mutex '&gsm->pvt->lock' freed more times than we've locked!
[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h538 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): mutex '&gsm->pvt->lock' freed more times than we've locked!
[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h555 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): Error releasing mutex: Operation not permitted
[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h555 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): Error releasing mutex: Operation not permitted

Here is the full log of a call.

-- Accepting call from '+17672454598' to 's' on channel 1, span 2
-- Executing [[email protected]:1] Answer("EXTRA/5-1", "") in new stack
-- Executing [[email protected]:2] Goto("EXTRA/5-1", "ext-group,600,1") in new stack
-- Goto (ext-group,600,1)
-- Executing [[email protected]:1] Macro("EXTRA/5-1", "user-callerid,") in new stack
-- Executing [[email protected]:1] Set("EXTRA/5-1", "AMPUSER=+17672454598") in new stack
-- Executing [[email protected]:2] GotoIf("EXTRA/5-1", "0?report") in new stack
-- Executing [[email protected]:3] ExecIf("EXTRA/5-1", "1?Set(REALCALLERIDNUM=+17672454598)") in new stack
-- Executing [[email protected]:4] Set("EXTRA/5-1", "AMPUSER=") in new stack
-- Executing [[email protected]:5] Set("EXTRA/5-1", "AMPUSERCIDNAME=") in new stack
-- Executing [[email protected]:6] GotoIf("EXTRA/5-1", "1?report") in new stack
-- Goto (macro-user-callerid,s,10)
-- Executing [[email protected]:10] GotoIf("EXTRA/5-1", "0?continue") in new stack
-- Executing [[email protected]:11] Set("EXTRA/5-1", "__TTL=64") in new stack
-- Executing [[email protected]:12] GotoIf("EXTRA/5-1", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [[email protected]:19] NoOp("EXTRA/5-1", "Using CallerID "+17672454598" <+17672454598>") in new stack
-- Executing [[email protected]:2] GotoIf("EXTRA/5-1", "1?skipdb") in new stack
-- Goto (ext-group,600,4)
-- Executing [[email protected]:4] Set("EXTRA/5-1", "__NODEST=") in new stack
-- Executing [[email protected]:5] Set("EXTRA/5-1", "__BLKVM_OVERRIDE=BLKVM/600/EXTRA/5-1") in new stack
-- Executing [[email protected]:6] Set("EXTRA/5-1", "__BLKVM_BASE=600") in new stack
-- Executing [[email protected]:7] Set("EXTRA/5-1", "DB(BLKVM/600/EXTRA/5-1)=TRUE") in new stack
-- Executing [[email protected]:8] Set("EXTRA/5-1", "RRNODEST=") in new stack
-- Executing [[email protected]:9] Set("EXTRA/5-1", "__NODEST=600") in new stack
-- Executing [[email protected]:10] Set("EXTRA/5-1", "RecordMethod=Group") in new stack
-- Executing [[email protected]:11] Macro("EXTRA/5-1", "record-enable,205-200-204-201,Group") in new stack
-- Executing [[email protected]:1] GotoIf("EXTRA/5-1", "1?check") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [[email protected]:4] AGI("EXTRA/5-1", "recordingcheck,20110311-193129,1299886289.636") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
-- <EXTRA/5-1>AGI Script recordingcheck completed, returning 0
-- Executing [[email protected]:5] MacroExit("EXTRA/5-1", "") in new stack
-- Executing [[email protected]:12] Set("EXTRA/5-1", "RingGroupMethod=memoryhunt") in new stack
-- Executing [[email protected]:13] Macro("EXTRA/5-1", "dial,10,tr,205-200-204-201") in new stack
-- Executing [[email protected]:1] GotoIf("EXTRA/5-1", "1?dial") in new stack
-- Goto (macro-dial,s,3)
-- Executing [[email protected]:3] AGI("EXTRA/5-1", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Caller ID name is '+17672454598' number is '+17672454598'
dialparties.agi: Methodology of ring is 'memoryhunt'
-- dialparties.agi: Added extension 205 to extension map
-- dialparties.agi: Added extension 200 to extension map
-- dialparties.agi: Added extension 204 to extension map
-- dialparties.agi: Added extension 201 to extension map
-- dialparties.agi: Extension 205 cf is disabled
-- dialparties.agi: Extension 200 cf is disabled
-- dialparties.agi: Extension 204 cf is disabled
-- dialparties.agi: Extension 201 cf is disabled
-- dialparties.agi: Extension 205 do not disturb is disabled
-- dialparties.agi: Extension 200 do not disturb is disabled
-- dialparties.agi: Extension 204 do not disturb is disabled
-- dialparties.agi: Extension 201 do not disturb is disabled
-- dialparties.agi: Filtered ARG3: 205-200-204-201
-- <EXTRA/5-1>AGI Script dialparties.agi completed, returning 0
-- Executing [[email protected]:20] NoOp("EXTRA/5-1", "Returned from dialparties with hunt groups to dial ") in new stack
-- Executing [[email protected]:21] Set("EXTRA/5-1", "HuntLoop=0") in new stack
-- Executing [[email protected]:22] GotoIf("EXTRA/5-1", "1?a30") in new stack
-- Goto (macro-dial,s,26)
-- Executing [[email protected]:26] Set("EXTRA/5-1", "HuntMember=HuntMember0") in new stack
-- Executing [[email protected]:27] GotoIf("EXTRA/5-1", "0?a32:a35") in new stack
-- Goto (macro-dial,s,31)
-- Executing [[email protected]:31] GotoIf("EXTRA/5-1", "1?a36:a50") in new stack
-- Goto (macro-dial,s,32)
-- Executing [[email protected]:32] Set("EXTRA/5-1", "CTLoop=0") in new stack
-- Executing [[email protected]:33] GotoIf("EXTRA/5-1", "0?a42") in new stack
-- Executing [[email protected]:34] Set("EXTRA/5-1", "CT_EXTEN=205") in new stack
-- Executing [[email protected]:35] Set("EXTRA/5-1", "DB(CALLTRACE/205)=+17672454598") in new stack
-- Executing [[email protected]:36] Set("EXTRA/5-1", "CTLoop=1") in new stack
-- Executing [[email protected]:37] Goto("EXTRA/5-1", "s,a37") in new stack
-- Goto (macro-dial,s,33)
-- Executing [[email protected]:33] GotoIf("EXTRA/5-1", "1?a42") in new stack
-- Goto (macro-dial,s,38)
-- Executing [[email protected]:38] Dial("EXTRA/5-1", "SIP/205,10,trM(auto-blkvm)") in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Using SIP VRTP TOS bits 136
== Using SIP VRTP CoS mark 6
-- Called 205
[Mar 11 19:31:30] DEBUG[4146]: pbx.c:3198 ast_hint_extension: FONALITY: This thread has already held the conlock, skip locking
-- SIP/205-000001e7 is ringing
-- Nobody picked up in 10000 ms
-- Executing [[email protected]:39] Set("EXTRA/5-1", "HuntLoop=1") in new stack
-- Executing [[email protected]:40] GotoIf("EXTRA/5-1", "1?a46") in new stack
-- Goto (macro-dial,s,42)
-- Executing [[email protected]:42] Set("EXTRA/5-1", "HuntMembers=3") in new stack
-- Executing [[email protected]:43] Goto("EXTRA/5-1", "s,a22") in new stack
-- Goto (macro-dial,s,22)
-- Executing [[email protected]:22] GotoIf("EXTRA/5-1", "1?a30") in new stack
-- Goto (macro-dial,s,26)
-- Executing [[email protected]:26] Set("EXTRA/5-1", "HuntMember=HuntMember1") in new stack
-- Executing [[email protected]:27] GotoIf("EXTRA/5-1", "0?a32:a35") in new stack
-- Goto (macro-dial,s,31)
-- Executing [[email protected]:31] GotoIf("EXTRA/5-1", "1?a36:a50") in new stack
-- Goto (macro-dial,s,32)
-- Executing [[email protected]:32] Set("EXTRA/5-1", "CTLoop=0") in new stack
-- Executing [[email protected]:33] GotoIf("EXTRA/5-1", "0?a42") in new stack
-- Executing [[email protected]:34] Set("EXTRA/5-1", "CT_EXTEN=205") in new stack
-- Executing [[email protected]:35] Set("EXTRA/5-1", "DB(CALLTRACE/205)=+17672454598") in new stack
-- Executing [[email protected]:36] Set("EXTRA/5-1", "CTLoop=1") in new stack
-- Executing [[email protected]:37] Goto("EXTRA/5-1", "s,a37") in new stack
-- Goto (macro-dial,s,33)
-- Executing [[email protected]:33] GotoIf("EXTRA/5-1", "0?a42") in new stack
-- Executing [[email protected]:34] Set("EXTRA/5-1", "CT_EXTEN=200") in new stack
-- Executing [[email protected]:35] Set("EXTRA/5-1", "DB(CALLTRACE/200)=+17672454598") in new stack
-- Executing [[email protected]:36] Set("EXTRA/5-1", "CTLoop=2") in new stack
-- Executing [[email protected]:37] Goto("EXTRA/5-1", "s,a37") in new stack
-- Goto (macro-dial,s,33)
-- Executing [[email protected]:33] GotoIf("EXTRA/5-1", "1?a42") in new stack
-- Goto (macro-dial,s,38)
-- Executing [[email protected]:38] Dial("EXTRA/5-1", "SIP/205&SIP/200,10,trM(auto-blkvm)") in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Using SIP VRTP TOS bits 136
== Using SIP VRTP CoS mark 6
[Mar 11 19:31:40] DEBUG[4146]: pbx.c:3198 ast_hint_extension: FONALITY: This thread has already held the conlock, skip locking
-- Called 205
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Using SIP VRTP TOS bits 136
== Using SIP VRTP CoS mark 6
-- Called 200
[Mar 11 19:31:40] DEBUG[4146]: pbx.c:3198 ast_hint_extension: FONALITY: This thread has already held the conlock, skip locking
[Mar 11 19:31:40] DEBUG[4146]: pbx.c:3198 ast_hint_extension: FONALITY: This thread has already held the conlock, skip locking
-- SIP/200-000001e9 is ringing
-- SIP/205-000001e8 is ringing
[Mar 11 19:31:48] DEBUG[4146]: pbx.c:3198 ast_hint_extension: FONALITY: This thread has already held the conlock, skip locking
-- SIP/205-000001e8 answered EXTRA/5-1
-- Executing [[email protected]:1] Set("SIP/205-000001e8", "__MACRO_RESULT=") in new stack
-- Executing [[email protected]:2] DBdel("SIP/205-000001e8", "BLKVM/600/EXTRA/5-1") in new stack
-- DBdel: family=BLKVM, key=600/EXTRA/5-1
[Mar 11 19:31:48] DEBUG[4146]: pbx.c:3198 ast_hint_extension: FONALITY: This thread has already held the conlock, skip locking
-- Executing [[email protected]:1] Macro("EXTRA/5-1", "hangupcall") in new stack
-- Executing [[email protected]:1] GotoIf("EXTRA/5-1", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,4)
-- Executing [[email protected]:4] GotoIf("EXTRA/5-1", "0?skipblkvm") in new stack
-- Executing [[email protected]:5] NoOp("EXTRA/5-1", "Cleaning Up Block VM Flag: BLKVM/600/EXTRA/5-1") in new stack
-- Executing [[email protected]:6] DBdel("EXTRA/5-1", "BLKVM/600/EXTRA/5-1") in new stack
-- DBdel: family=BLKVM, key=600/EXTRA/5-1
-- DBdel: Error deleting key from database.
-- Executing [[email protected]:7] GotoIf("EXTRA/5-1", "1?theend") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing [[email protected]:9] Hangup("EXTRA/5-1", "") in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'EXTRA/5-1' in macro 'hangupcall'
== Spawn extension (macro-dial, h, 1) exited non-zero on 'EXTRA/5-1'
== Spawn extension (macro-dial, s, 38) exited non-zero on 'EXTRA/5-1' in macro 'dial'
[Mar 11 19:31:58] DEBUG[4146]: pbx.c:3198 ast_hint_extension: FONALITY: This thread has already held the conlock, skip locking
== Spawn extension (ext-group, 600, 13) exited non-zero on 'EXTRA/5-1'
-- Hungup 'EXTRA/5-1'
[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h538 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): mutex '&gsm->pvt->lock' freed more times than we've locked!
[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h538 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): mutex '&gsm->pvt->lock' freed more times than we've locked!
[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h555 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): Error releasing mutex: Operation not permitted
[Mar 11 19:31:59] ERROR[4157]: /usr/src/redhat/SOURCES/asterisk16-1.6.0.26/include/asterisk/lock.h555 __ast_pthread_mutex_unlock: chan_extra.c line 9311 (gsm_dchannel): Error releasing mutex: Operation not permitted

Hi,
Every time when the call hangup, it will show such information?

Hi,
Which version of chan-extra do you install? Chan-extra 1.0.3?

1.0.2.1. Should i install 1.0.3? But the error is no big problem, correct?

Hi,
You don't need to install 1.0.3. Up to now, it's not big problem.