TOMMY MYOTOMMY MYO 

Dear Sir/

 I can't load TDM410 on my Elastix VM machine.

I have attached all necessary infomation.

Is there any limitation with TDM410 with ESXi 5.1 ?TDM410 card is successfully loaded in ESXi PCI passthrough and added in VM. but after installing Elastix, the TDM card is having following error and cannot boot successfully.


User-added image
User-added image

Kernel
   Linux(x86_64)-2.6.18-371.11.1.el5

Elastix
   elastix-2.4.0-2
   elastix-a2billing-1.9.4-5
   elastix-addons-2.4.0-7
   elastix-agenda-2.4.0-11
   elastix-asterisk-sounds-1.2.3-1
   elastix-email_admin-2.4.0-5
   elastix-extras-2.4.0-4
   elastix-fax-2.4.0-3
   elastix-firstboot-2.4.0-4
   elastix-framework-2.4.0-12
   elastix-im-2.4.0-2
   elastix-my_extension-2.4.0-3
   elastix-pbx-2.4.0-7
   elastix-portknock-0.0.1-0
   elastix-reports-2.4.0-4
   elastix-security-2.4.0-6
   elastix-system-2.4.0-11
   elastix-vtigercrm-5.2.1-7

RoundCubeMail
   RoundCubeMail-0.3.1-12

Mail
   postfix-2.3.3-6.el5
   cyrus-imapd-2.3.7-12.el5_7.2

IM
   openfire-3.7.1-1

FreePBX
   freePBX-2.8.1-17

Asterisk
   asterisk-11.11.0-0
   asterisk-perl-1.03-0
   asterisk-addons-11.11.0-0

FAX
   hylafax-4.3.11-0rhel5
   iaxmodem-1.2.0-2

DRIVERS
   dahdi-2.9.2-1
   rhino-0.99.6-2.b4
   wanpipe-util-7.0.10-1
Infobarra SolucoesInfobarra Solucoes 
Hi

We have accquired at the company a Digium TE420 Pci-e X1 card to connect on our Asterisk Server, in order to use our E1 R2 line from our Telephony Provider.

We currently have a E1 with 99 Extension numbers supplied by the telephony company.

Ok so first things first i have installed the card and it recognized ok, i have set up the dahdi trunk and all the inbound and outbound routes.

I can receive and make phone calls, but i have an odd isue, after 2 or 3 minutes or even after 1minute call hangup and i get the following error message attached on the log.

Please i kindly need some advise regarding the error as i cannot find any other tips anywhere.

And its not a telephony line problem because we have a PABX old system running on the same Line just fine no call hangups, only issue is the old PABX system cannot make IP hibrid calls neither call recordings, this was one of the reasons why we have decided to upgrade this to Asterisk.


So below is the error message i get on the call hangup.

BTW- I am using a RJ45 cable directly from the PC digium card Interface1 to my FiberOptic ISP provider Modem RJ45 port dedicated for usage of the E1 telephony.
cable is 60cm lenght, with pinouts   Side A 1,2          Side B 4,5



below the output of the log debug




[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: cdr_mysql.c:343 mysql_log: Inserting a CDR record.
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: cdr_mysql.c:346 mysql_log: SQL command as follows: INSERT INTO cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`,`cnum`,`cnam`,`outbound_cnum`,`outbound_cnam`) VALUES ('2017-05-19 09:09:42','\"intelbras\" <4193>','4193','020153939','from-internal','SIP/4193-00000000','DAHDI/1-1','Dial','DAHDI/g0/20153939,300,','168','151','ANSWERED','3','1495195782.0','4193','intelbras','4193','intelbras')
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: channel.c:2843 ast_hangup: Hanging up channel 'SIP/3538-00000001'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(start) result is '2017-05-19 09:09:42'
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_sip.c:6929 sip_hangup: Hangup call SIP/3538-00000001, SIP callid 36e20b207ed6556b3f3978f23136428f@177.85.198.35:5060
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_sip.c:6564 update_call_counter: Updating call counter for outgoing call
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(clid) result is '"intelbras" <4193>'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(dcontext) result is 'from-internal'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(channel) result is 'SIP/4193-00000000'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(dstchannel) result is 'DAHDI/1-1'
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: res_rtp_asterisk.c:4805 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f1bc4032e68'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(lastapp) result is 'Dial'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(lastdata) result is 'DAHDI/g0/20153939,300,'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(duration) result is '168'
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:345 _ast_device_state: No provider found, checking channel drivers for SIP - 3538
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(billsec) result is '151'
[2017-05-19 09:12:30] DEBUG[909]: chan_sip.c:30079 sip_devicestate: Checking device state for peer 3538
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(disposition) result is 'ANSWERED'
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:477 do_state_change: Changing state for SIP/3538 - state 1 (Not in use)
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(amaflags) result is 'DOCUMENTATION'
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:452 devstate_event: device 'SIP/3538' state '1'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(accountcode) result is '(null)'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(uniqueid) result is '1495195782.0'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(userfield) result is '(null)'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(test) result is '(null)'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(src) result is '4193'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:4837 pbx_substitute_variables_helper_full: Function CDR(dst) result is '020153939'
[2017-05-19 09:12:30] DEBUG[980]: app_queue.c:1924 handle_statechange: Device 'SIP/3538' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: cdr_sqlite3_custom.c:261 write_cdr: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test,src,dst) VALUES ('2017-05-19 09:09:42','"intelbras" <4193>','from-internal','SIP/4193-00000000','DAHDI/1-1','Dial','DAHDI/g0/20153939,300,','168','151','ANSWERED','DOCUMENTATION','','1495195782.0','','','4193','020153939')
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '177.99.250.245:63141' into...
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '177.99.250.245' and port '63141'.
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_sip.c:3731 __sip_xmit: Trying to put 'BYE sip:412' onto UDP socket destined for 177.99.250.245:63141
[2017-05-19 09:12:30] DEBUG[911]: app_queue.c:2026 extension_state_cb: Extension '3538@ext-local' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:345 _ast_device_state: No provider found, checking channel drivers for SIP - 3538
[2017-05-19 09:12:30] DEBUG[909]: chan_sip.c:30079 sip_devicestate: Checking device state for peer 3538
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/3538-00000001
Variable: RTPAUDIOQOS
Value: ssrc=2063464198;themssrc=873731195;lp=1;rxjitter=0.000000;rxcount=7561;txjitter=0.012451;txcount=7569;rlp=2;rtt=0.002000
Uniqueid: 1495195796.3


[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:477 do_state_change: Changing state for SIP/3538 - state 1 (Not in use)
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:452 devstate_event: device 'SIP/3538' state '1'
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/3538-00000001
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1495195796.3


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/3538-00000001
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1495195796.3


[2017-05-19 09:12:30] DEBUG[980]: app_queue.c:1924 handle_statechange: Device 'SIP/3538' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/3538-00000001
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1495195796.3


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/3538-00000001
Variable: RTPAUDIOQOS
Value: ssrc=2063464198;themssrc=873731195;lp=1;rxjitter=0.000000;rxcount=7561;txjitter=0.012451;txcount=7569;rlp=2;rtt=0.002000
Uniqueid: 1495195796.3


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 3538
Context: ext-local
Hint: SIP/3538,CustomPresence:3538
Status: 0


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: Hangup
Privilege: call,all
Channel: SIP/3538-00000001
Uniqueid: 1495195796.3
CallerIDNum: 3538
CallerIDName: LG2
ConnectedLineNum: 1120153939
ConnectedLineName: 1120153939
AccountCode:
Cause: 16
Cause-txt: Normal Clearing


[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: app_dial.c:3120 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: app_macro.c:449 _macro_exec: Spawn extension (macro-dial-one,s,43) exited non-zero on 'DAHDI/7-1' in macro 'dial-one'
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: Dial
Privilege: call,all
SubEvent: End
Channel: DAHDI/7-1
UniqueID: 1495195796.2
DialStatus: ANSWER


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: ARG1
Value: novm
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: ARG2
Value: 3538
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: app_macro.c:449 _macro_exec: Spawn extension (macro-exten-vm,s,9) exited non-zero on 'DAHDI/7-1' in macro 'exten-vm'
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: pbx.c:6789 __ast_pbx_run: Spawn extension (from-did-direct,3538,2) exited non-zero on 'DAHDI/7-1'
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: channel.c:2664 ast_softhangup_nolock: Soft-Hanging up channel 'DAHDI/7-1'
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: channel.c:2843 ast_hangup: Hanging up channel 'DAHDI/7-1'
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:6659 dahdi_hangup: dahdi_hangup(DAHDI/7-1)
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:6863 dahdi_hangup: Hangup: channel: 7 index = 0, normal = 18, callwait = -1, thirdcall = -1
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:6989 dahdi_hangup: disconnecting MFC/R2 call on chan 7
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 7 - Call ended
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 7 - CAS Tx >> [IDLE] 0x08
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 7 - CAS Raw Tx >> 0x09
MFC/R2 call end on channel 7
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:5414 dahdi_disable_ec: Disabled echo cancellation on channel 7
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:7309 dahdi_setoption: Set option TDD MODE, value: OFF(0) on DAHDI/7-1
[2017-05-19 09:12:30] DEBUG[1213][C-00000002]: chan_dahdi.c:5326 update_conf: Updated conferencing on 7, with 0 conference users
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:345 _ast_device_state: No provider found, checking channel drivers for DAHDI - 7
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:477 do_state_change: Changing state for DAHDI/7 - state 0 (Unknown)
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:452 devstate_event: device 'DAHDI/7' state '0'
[2017-05-19 09:12:30] DEBUG[980]: app_queue.c:1924 handle_statechange: Device 'DAHDI/7' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: ARG3
Value: 0
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: MACRO_EXTEN
Value: 3538
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: MACRO_CONTEXT
Value: from-did-direct
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: MACRO_PRIORITY
Value: 2
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: DAHDI/7-1
Variable: MACRO_DEPTH
Value: 0
Uniqueid: 1495195796.2


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: SoftHangupRequest
Privilege: call,all
Channel: DAHDI/7-1
Uniqueid: 1495195796.2
Cause: 16


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: Hangup
Privilege: call,all
Channel: DAHDI/7-1
Uniqueid: 1495195796.2
CallerIDNum: 1120153939
CallerIDName: 1120153939
ConnectedLineNum: 4100
ConnectedLineName: DDR-OI-IN
AccountCode:
Cause: 16
Cause-txt: Normal Clearing


[2017-05-19 09:12:30] DEBUG[919]: chan_sip.c:9076 find_call: = Looking for  Call ID: 36e20b207ed6556b3f3978f23136428f@177.85.198.35:5060 (Checking To) --From tag as78802ce2 --To-tag 29336d3d
[2017-05-19 09:12:30] DEBUG[919][C-00000002]: chan_sip.c:4429 __sip_ack: Stopping retransmission on '36e20b207ed6556b3f3978f23136428f@177.85.198.35:5060' of Request 103: Match Found
[2017-05-19 09:12:30] DEBUG[919]: chan_sip.c:6379 sip_pvt_dtor: Destroying SIP dialog 36e20b207ed6556b3f3978f23136428f@177.85.198.35:5060
[2017-05-19 09:12:30] DEBUG[919]: rtp_engine.c:232 instance_destructor: Destroyed RTP instance '0x7f1bc4032e68'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: channel.c:2843 ast_hangup: Hanging up channel 'DAHDI/1-1'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:6659 dahdi_hangup: dahdi_hangup(DAHDI/1-1)
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:6863 dahdi_hangup: Hangup: channel: 1 index = 0, normal = 12, callwait = -1, thirdcall = -1
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:6989 dahdi_hangup: disconnecting MFC/R2 call on chan 1
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:6623 dahdi_ast_cause_to_r2_cause: ast cause 16 resulted in openr2 cause 6/Normal Clearing
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - CAS Tx >> [CLEAR FORWARD] 0x08
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - CAS Raw Tx >> 0x09
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:5414 dahdi_disable_ec: Disabled echo cancellation on channel 1
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:7309 dahdi_setoption: Set option TDD MODE, value: OFF(0) on DAHDI/1-1
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_dahdi.c:5326 update_conf: Updated conferencing on 1, with 0 conference users
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:345 _ast_device_state: No provider found, checking channel drivers for DAHDI - 1
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: Hangup
Privilege: call,all
Channel: DAHDI/1-1
Uniqueid: 1495195782.1
CallerIDNum: 020153939
CallerIDName: CID:4193
ConnectedLineNum: 4193
ConnectedLineName: intelbras
AccountCode:
Cause: 16
Cause-txt: Normal Clearing


[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:477 do_state_change: Changing state for DAHDI/1 - state 0 (Unknown)
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:452 devstate_event: device 'DAHDI/1' state '0'
[2017-05-19 09:12:30] DEBUG[980]: app_queue.c:1924 handle_statechange: Device 'DAHDI/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: app_dial.c:3120 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/4193-00000000
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1495195782.0


[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: app_macro.c:449 _macro_exec: Spawn extension (macro-dialout-trunk,s,22) exited non-zero on 'SIP/4193-00000000' in macro 'dialout-trunk'
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: Dial
Privilege: call,all
SubEvent: End
Channel: SIP/4193-00000000
UniqueID: 1495195782.0
DialStatus: ANSWER


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/4193-00000000
Variable: MACRO_DEPTH
Value: 0
Uniqueid: 1495195782.0


[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: pbx.c:6789 __ast_pbx_run: Spawn extension (from-internal,020153939,6) exited non-zero on 'SIP/4193-00000000'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: channel.c:2664 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/4193-00000000'
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: SoftHangupRequest
Privilege: call,all
Channel: SIP/4193-00000000
Uniqueid: 1495195782.0
Cause: 16


[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: channel.c:2843 ast_hangup: Hanging up channel 'SIP/4193-00000000'
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_sip.c:6929 sip_hangup: Hangup call SIP/4193-00000000, SIP callid 3840729022@172.25.0.137
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_sip.c:6564 update_call_counter: Updating call counter for incoming call
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:345 _ast_device_state: No provider found, checking channel drivers for SIP - 4193
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: res_rtp_asterisk.c:4805 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f1b8003aa68'
[2017-05-19 09:12:30] DEBUG[909]: chan_sip.c:30079 sip_devicestate: Checking device state for peer 4193
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:477 do_state_change: Changing state for SIP/4193 - state 1 (Not in use)
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:452 devstate_event: device 'SIP/4193' state '1'
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/4193-00000000
Variable: RTPAUDIOQOS
Value: ssrc=1190990024;themssrc=1092193669;lp=1;rxjitter=0.000000;rxcount=7634;txjitter=0.000196;txcount=7674;rlp=3;rtt=0.029000
Uniqueid: 1495195782.0


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/4193-00000000
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1495195782.0


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/4193-00000000
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1495195782.0


[2017-05-19 09:12:30] DEBUG[980]: app_queue.c:1924 handle_statechange: Device 'SIP/4193' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 4193
Context: ext-local
Hint: SIP/4193,CustomPresence:4193
Status: 0


[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/4193-00000000
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1495195782.0


[2017-05-19 09:12:30] DEBUG[911]: app_queue.c:2026 extension_state_cb: Extension '4193@ext-local' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/4193-00000000
Variable: RTPAUDIOQOS
Value: ssrc=1190990024;themssrc=1092193669;lp=1;rxjitter=0.000000;rxcount=7634;txjitter=0.000196;txcount=7674;rlp=3;rtt=0.029000
Uniqueid: 1495195782.0


[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '177.99.250.245:5062' into...
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '177.99.250.245' and port '5062'.
[2017-05-19 09:12:30] DEBUG[1205][C-00000000]: chan_sip.c:3731 __sip_xmit: Trying to put 'BYE sip:419' onto UDP socket destined for 177.99.250.245:5062
[2017-05-19 09:12:30] DEBUG[983]: manager.c:4879 match_filter: Examining event:
Event: Hangup
Privilege: call,all
Channel: SIP/4193-00000000
Uniqueid: 1495195782.0
CallerIDNum: 4193
CallerIDName: intelbras
ConnectedLineNum: 20153939
ConnectedLineName: CID:4193
AccountCode:
Cause: 16
Cause-txt: Normal Clearing


[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:345 _ast_device_state: No provider found, checking channel drivers for SIP - 4193
[2017-05-19 09:12:30] DEBUG[909]: chan_sip.c:30079 sip_devicestate: Checking device state for peer 4193
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:477 do_state_change: Changing state for SIP/4193 - state 1 (Not in use)
[2017-05-19 09:12:30] DEBUG[909]: devicestate.c:452 devstate_event: device 'SIP/4193' state '1'
[2017-05-19 09:12:30] DEBUG[980]: app_queue.c:1924 handle_statechange: Device 'SIP/4193' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2017-05-19 09:12:30] DEBUG[919]: chan_sip.c:9076 find_call: = Looking for  Call ID: 3840729022@172.25.0.137 (Checking To) --From tag as63172d1c --To-tag 914066215
[2017-05-19 09:12:30] DEBUG[919][C-00000000]: chan_sip.c:4429 __sip_ack: Stopping retransmission on '3840729022@172.25.0.137' of Request 102: Match Found
[2017-05-19 09:12:30] DEBUG[919]: chan_sip.c:6379 sip_pvt_dtor: Destroying SIP dialog 3840729022@172.25.0.137
[2017-05-19 09:12:30] DEBUG[919]: rtp_engine.c:232 instance_destructor: Destroyed RTP instance '0x7f1b8003aa68'
[2017-05-19 09:12:30] DEBUG[924]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 2 - Bits changed from 0x00 to 0x08
[2017-05-19 09:12:30] DEBUG[925]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 3 - Bits changed from 0x04 to 0x08
[2017-05-19 09:12:30] DEBUG[924]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 2 - CAS Rx << [CLEAR FORWARD] 0x08
[2017-05-19 09:12:30] DEBUG[925]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 3 - CAS Rx << [IDLE] 0x08
[2017-05-19 09:12:30] NOTICE[925]: chan_dahdi.c:4616 dahdi_r2_on_line_idle: Far end unblocked on chan 3
Chan 2 - Far end disconnected. Reason: Normal Clearing
MFC/R2 call disconnected on channel 2
[2017-05-19 09:12:30] DEBUG[924]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 2 - Call ended
[2017-05-19 09:12:30] DEBUG[924]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 2 - CAS Tx >> [IDLE] 0x08
[2017-05-19 09:12:30] DEBUG[924]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 2 - CAS Raw Tx >> 0x09
MFC/R2 call end on channel 2
[2017-05-19 09:12:30] DEBUG[931]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 9 - Bits changed from 0x00 to 0x08
[2017-05-19 09:12:30] DEBUG[931]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 9 - CAS Rx << [CLEAR FORWARD] 0x08
Chan 9 - Far end disconnected. Reason: Normal Clearing
MFC/R2 call disconnected on channel 9
[2017-05-19 09:12:30] DEBUG[931]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 9 - Call ended
[2017-05-19 09:12:30] DEBUG[931]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 9 - CAS Tx >> [IDLE] 0x08
[2017-05-19 09:12:30] DEBUG[931]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 9 - CAS Raw Tx >> 0x09
MFC/R2 call end on channel 9
[2017-05-19 09:12:30] DEBUG[923]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - Bits changed from 0x08 to 0x04
[2017-05-19 09:12:30] DEBUG[923]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - CAS Rx << [0x04] 0x04
[2017-05-19 09:12:30] ERROR[923]: chan_dahdi.c:4585 dahdi_r2_write_log: Chan 1 - Protocol error. Reason = Invalid CAS, R2 State = Clear Forward Transmitted, MF state = MF Engine Off, MF Group = Forward Group II, CAS = 0x04
DNIS = 20153939, ANI = 4193, MF = 0x20
[2017-05-19 09:12:30] DEBUG[923]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - CAS Tx >> [IDLE] 0x08
[2017-05-19 09:12:30] DEBUG[923]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - CAS Raw Tx >> 0x09
[2017-05-19 09:12:30] ERROR[923]: chan_dahdi.c:4345 dahdi_r2_on_protocol_error: MFC/R2 protocol error on chan 1: Invalid CAS
[2017-05-19 09:12:30] DEBUG[923]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - Bits changed from 0x04 to 0x08
[2017-05-19 09:12:30] DEBUG[923]: chan_dahdi.c:4592 dahdi_r2_write_log: Chan 1 - CAS Rx << [IDLE] 0x08
[2017-05-19 09:12:30] NOTICE[923]: chan_dahdi.c:4616 dahdi_r2_on_line_idle: Far end unblocked on chan 1
[2017-05-19 09:12:37] DEBUG[919]: chan_sip.c:4285 __sip_autodestruct: Auto destroying SIP dialog 'TM8DR9wSGABIKfte9pd4nQ..'
[2017-05-19 09:12:37] DEBUG[919]: chan_sip.c:6379 sip_pvt_dtor: Destroying SIP dialog TM8DR9wSGABIKfte9pd4nQ..




Please any help will be appreciated.

Kind regards
Infobarra
Charles ALICharles ALI 
Hello,
what was the alarm by default on a card, that is without having connected a line to our card.
Alarm RED is normal when we are not connected to our telco?
Thank you
Ken UlrichKen Ulrich 
Hello All,

I currently have a regular RJ11 cordless phone plugged into my Cable Provider (MediaCom) for my Phone Number.

I would like to just replace the cordless phone with the Switchvox unit and go from there.

I am just needing to know 2 things.

1. What type of card ( I believe I would need a FXS) would I need to achieve this?

2. Would there be any settings/etc that needs to be done on Mediacom side?

This is basically a Coax Cable going into their(MediaCom) modem, that is used for both my Internet, and Phone Service(I plug a RJ11 cable into the modem that connects to my current cordless phone).

I hope this is enough information.

Thank you!
Charles ALICharles ALI 

Hello,
We have two Elastix NLX 4000 servers, with two  Digium cards TE131 / TE133, They have all been working fine up until now. But for two days, we have problems.
Outbound call show:
[2016-06-28 06:13:20] WARNING[10307][C-00000000]: app_dial.c:2437 dial_exec_full: Unable to create channel of type 'DAHDI' (cause 34 - Circuit/channel congestion)
  == Everyone is busy/congested at this time (1:0/1/0)
    -- Executing [s@macro-dialout-trunk:23] NoOp("SIP/8000-00000000", "Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 34") in new stack

The system shows that cards are detected well and configured (with the commands dmesg and vim /etc/var/log /messages) but when we make “dahdi show status” (without having connected the E1 line ) we have:
elx*CLI> dahdi show status
Description                              Alarms  IRQ    bpviol CRC    Fra Codi Options  LBO
Wildcard TE131/TE133 Card 0              BLU/RED 0      0      0      CCS HDB3          0 db (CSU)/0-133 feet (DSX-1)
elx*CLI>
 
The  Alarms must be OK
Our two cards simultaneously had the same problem.
And when we active PRI debug, we have
elx*CLI> pri set debug on span 1

Enabled debugging on span 1

PRI Span: 1 TEI=0 Sending SABME

PRI Span: 1 TEI=0 MDL-ERROR (G): T200 expired N200 times sending SABME in state 5(Awaiting establishment)

PRI Span: 1 Changing from state 5(Awaiting establishment) to 4(TEI assigned)

PRI Span: 1 TEI=0 DL event: Q931_DL_EVENT_DL_RELEASE_IND(3)

PRI Span: 1 SAPI/TEI=0/0 Kick starting link

PRI Span: 1 TEI=0 Sending SABME

PRI Span: 1 Changing from state 4(TEI assigned) to 5(Awaiting establishment)

PRI Span: 1 TEI=0 Sending SABME

PRI Span: 1 TEI=0 Sending SABME

PRI Span: 1 TEI=0 Sending SABME

PRI Span: 1 TEI=0 MDL-ERROR (G): T200 expired N200 times sending SABME in state 5(Awaiting establishment)

PRI Span: 1 Changing from state 5(Awaiting establishment) to 4(TEI assigned)

PRI Span: 1 TEI=0 DL event: Q931_DL_EVENT_DL_RELEASE_IND(3)

PRI Span: 1 SAPI/TEI=0/0 Kick starting link

PRI Span: 1 TEI=0 Sending SABME

PRI Span: 1 Changing from state 4(TEI assigned) to 5(Awaiting establishment)

 
 
Thank’s (sorry for my English)
 
Best Answer chosen by Colin Cuthbertson
Malcolm DavenportMalcolm Davenport
The res_timing_timerfd.so module should provide timing that is accurate as a res_timing_dahdi.so (provided by telephony cards).  You can see what timing module is loaded into Asterisk by performing:
# asterisk -rx "module show like timer"
If you see that res_timing_timerfd.so is in use and is running, then you're good.
Rafael RodríguezRafael Rodríguez 
Let me elaborate: Say there is an old or outdated, digium-compliant PCI-E card (lspci on CLI throws me Digium Comm) that should be working with a given dahdi version. If I installed the current (ie, most recent release) available DAHDI, should I be able to use the card just the same? Or must I stick to the old version? If I must stick with the old version, could there be problems using recent Asterisk releases with an old dahdi? Is there a way to downgrade my current dahdi?
Best Answer chosen by Rafael Rodríguez
DenisDenis (Sangoma) 
DAHDI still contains the drivers for old or updated cards, therefore you should be able to use it. This being said, please note that our Eng efforts to maintain the driver stop when the card reaches End of Life.  This means that an old driver has an small chance to create problems.

As regards of downgrade, you can downgrade the version of DAHDI, but you will required to recompile Asterisk, this option is not recommended as you may not be ale to install old version of DAHDI on new operating systems
Previous MonthNext Month
SunMonTueWedThuFriSat