Hello,
I’ve some little experience with Asterisk since 6-7 years, running about a dozen gateway, with various type of connectivity pri, sip, trunk etc.
I was running an old gateway with an E1 line, and we just upgraded it to ubuntu 16.06 and asterisk 13.26.
I’ve been struggling since a good week to understand an issue that i cannot fix:
*I’ve a basic dialplan entry that allow people to dial any number from their sip phone
the entry is:
exten => _X.,1,Answer
same => n,dial(DAHDI/i2/${EXTEN})
same => n,Hangup
This works perfectly well. people can place calls etc.
but any use of the originate command, either on the cli or via AMI miserably fail and I can’t find out why.
debugging pri the only info i get is a disconnect see below on a
channel originate DAHDI/i2/0033673848727 application playback beep
PRI Span: 2 – Making new call for cref 32771
PRI Span: 2
PRI Span: 2 > DL-DATA request
PRI Span: 2 > Protocol Discriminator: Q.931 (8) len=32
PRI Span: 2 > TEI=0 Call Ref: len= 2 (reference 3/0x3) (Sent from originator)
PRI Span: 2 > Message Type: SETUP (5)
PRI Span: 2 TEI=0 Transmitting N(S)=6, window is open V(A)=6 K=7
PRI Span: 2
PRI Span: 2 > Protocol Discriminator: Q.931 (8) len=32
PRI Span: 2 > TEI=0 Call Ref: len= 2 (reference 3/0x3) (Sent from originator)
PRI Span: 2 > Message Type: SETUP (5)
PRI Span: 2 > [04 03 80 90 a3]
PRI Span: 2 > Bearer Capability (len= 5) [ Ext: 1 Coding-Std: 0 Info transfer capability: Speech (0)
PRI Span: 2 > Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16)
PRI Span: 2 > User information layer 1: A-Law (35)
PRI Span: 2 > [18 03 a1 83 81]
PRI Span: 2 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Preferred Dchan: 0
PRI Span: 2 > ChanSel: As indicated in following octets
PRI Span: 2 > Ext: 1 Coding: 0 Number Specified Channel Type: 3
PRI Span: 2 > Ext: 1 Channel: 1 Type: CPE]
PRI Span: 2 > [70 0e 80 30 30 33 33 36 37 33 38 34 38 37 32 37]
PRI Span: 2 > Called Party Number (len=16) [ Ext: 1 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) ‘0033673848727’ ]
PRI Span: 2 > [a1]
PRI Span: 2 > Sending Complete (len= 1)
PRI Span: 2 q931.c:6531 q931_setup: Call 32771 enters state 1 (Call Initiated). Hold state: Idle
PRI Span: 2
PRI Span: 2 < Protocol Discriminator: Q.931 (8) len=10
PRI Span: 2 < TEI=0 Call Ref: len= 2 (reference 3/0x3) (Sent to originator)
PRI Span: 2 < Message Type: CALL PROCEEDING (2)
PRI Span: 2 < [18 03 a9 83 81]
PRI Span: 2 < Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0
PRI Span: 2 < ChanSel: As indicated in following octets
PRI Span: 2 < Ext: 1 Coding: 0 Number Specified Channel Type: 3
PRI Span: 2 < Ext: 1 Channel: 1 Type: CPE]
PRI Span: 2 Received message for call 0x7f97f0001610 on link 0x1d8c4d0 TEI/SAPI 0/0
PRI Span: 2 – Processing IE 24 (cs0, Channel ID)
PRI Span: 2 q931.c:9095 post_handle_q931_message: Call 32771 enters state 3 (Outgoing Call Proceeding). Hold state: Idle
Span 2: Processing event PRI_EVENT_PROCEEDING(13)
PRI Span: 2 q931.c:7332 q931_hangup: Hangup other cref:32771
PRI Span: 2 q931.c:7089 __q931_hangup: ourstate Outgoing Call Proceeding, peerstate Incoming Call Proceeding, hold-state Idle
PRI Span: 2 q931.c:6275 q931_disconnect: Call 32771 enters state 11 (Disconnect Request). Hold state: Idle
I’m a bit clueless on what to do…
given that the dial command is working well, i believe the whole dahdi configuration is good?
Thanks ambiorixg12! that was a good idea, so i played with it a bit, and find out a few more puzzling thing:
channel originate Local/0033673848727@dialoutcon extension 11@test
connect my phone number with the sip phone behind 11
but
channel originate Local/0033673848727@dialoutcon application playback beep
fails with a disconnect before my phone ring
and
channel originate DAHDI/i2/0033673848727 extension 11@test
also fails with a disconnect
quite puzzling… any idea?
steph
further tests help me identifying the problem in a better way: connecting 2 callers sip-pri pri-sip sip-sip or pri-pri works fine using cli originate or AMI
connecting a caller to an application like playback works fine if it is in call in, but connecting a caller to an application as callout (originate via cli or AMI using a local channel or not) does not work
any idea?
steph
Thanks for your answer. unfortunately the caller-id is not the issue. I tested this before.
I’ve the same problem with a call file where i get:
[May 14 12:58:31] NOTICE[5111]: pbx_spool.c:447 attempt_thread: Call failed to go through, reason (3) Remote end Ringing
same message with or without callerid id set.
Looking at debug, here is what i get:
[May 14 12:54:12] DEBUG[4954] pbx_spool.c: Filename: /var/spool/asterisk/outgoing/b.call, Retries: 0, max: 2
[May 14 12:54:12] DEBUG[4954] pbx_spool.c: Outgoing DAHDI/i2/0033673848727: StartRetry
[May 14 12:54:12] DEBUG[5059][C-0000000c] chan_dahdi.c: Using channel 32
[May 14 12:54:12] DEBUG[5059][C-0000000c] sig_pri.c: sig_pri_request 32
[May 14 12:54:12] DEBUG[5059][C-0000000c] stasis.c: Topic ‘channel:1557838452.12’: 0x7f7fb40016b8 created
[May 14 12:54:12] DEBUG[5059][C-0000000c] stasis.c: Topic ‘cache:27/channel:1557838452.12’: 0x7f7fb4001808 created
[May 14 12:54:12] DEBUG[5059][C-0000000c] channel.c: Channel 0x7f7fb4001aa8 ‘DAHDI/i2/0033673848727-d’ allocated
[May 14 12:54:12] DEBUG[5059][C-0000000c] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[May 14 12:54:12] DEBUG[5059][C-0000000c] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[May 14 12:54:12] DEBUG[1506] devicestate.c: No provider found, checking channel drivers for DAHDI - i2/0033673848727
[May 14 12:54:12] DEBUG[1506] devicestate.c: Changing state for DAHDI/i2/0033673848727 - state 2 (In use)
[May 14 12:54:12] DEBUG[5059] sig_pri.c: CALLER NAME: NUM:
[May 14 12:54:12] DEBUG[5059] sig_pri.c: prioffset: 1 mastertrunkgroup: 0 logicalspan: 0 result: 1
[May 14 12:54:12] DEBUG[1506] devicestate.c: No provider found, checking channel drivers for DAHDI - i2/0033673848727
[May 14 12:54:12] DEBUG[1506] devicestate.c: Changing state for DAHDI/i2/0033673848727 - state 2 (In use)
[May 14 12:54:12] DEBUG[1557][C-0000000c] sig_pri.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 2
[May 14 12:54:12] DEBUG[5059] channel.c: Channel 0x7f7fb4001aa8 ‘DAHDI/i2/0033673848727-d’ hanging up. Refs: 2
[May 14 12:54:12] DEBUG[5059] chan_dahdi.c: dahdi_hangup(DAHDI/i2/0033673848727-d)
[May 14 12:54:12] DEBUG[5059] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/i2/0033673848727-d
[May 14 12:54:12] DEBUG[5059] sig_pri.c: sig_pri_hangup 32
[May 14 12:54:12] DEBUG[5059] sig_pri.c: Channel ‘DAHDI/i2/0033673848727-d’ MOH-Event: SIG_PRI_MOH_EVENT_RESET in state SIG_PRI_MOH_STATE_IDLE
[May 14 12:54:12] DEBUG[5059] sig_pri.c: Channel ‘DAHDI/i2/0033673848727-d’ MOH-Next-State: $
[May 14 12:54:12] DEBUG[5059] sig_pri.c: Not yet hungup… Calling hangup with cause -1, and clearing call
[May 14 12:54:12] DEBUG[5059] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/i2/0033673848727-d
[May 14 12:54:12] DEBUG[5059] chan_dahdi.c: Updated conferencing on 32, with 0 conference users
[May 14 12:54:12] DEBUG[5059] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/i2/0033673848727-d
[May 14 12:54:12] DEBUG[5059] channel.c: Channel 0x7f7fb4001aa8 ‘DAHDI/i2/0033673848727-d’ destroying
[May 14 12:54:12] DEBUG[1507] cdr.c: Finalized CDR for DAHDI/i2/0033673848727-d - start 1557838452.081257 answer 0.000000 end 1557838452.595174 dispo
FAILED
[May 14 12:54:12] DEBUG[1507] cdr.c: Skipping CDR for DAHDI/i2/0033673848727-d since we weren’t answered
[May 14 12:54:12] DEBUG[5059] stasis.c: Topic ‘cache:27/channel:1557838452.12’: 0x7f7fb4001808 destroyed
[May 14 12:54:12] DEBUG[5059] stasis.c: Topic ‘channel:1557838452.12’: 0x7f7fb40016b8 destroyed
[May 14 12:54:12] DEBUG[1506] devicestate.c: No provider found, checking channel drivers for DAHDI - i2/0033673848727
[May 14 12:54:12] DEBUG[1506] devicestate.c: Changing state for DAHDI/i2/0033673848727 - state 0 (Unknown)
[May 14 12:54:12] NOTICE[5059] pbx_spool.c: Call failed to go through, reason (3) Remote end Ringing
is the issue related to “No provider found, checking channel drivers for DAHDI - i2/0033673848727” ?
any idea what is the meaning?
What is really strange is that the same machine under ubuntu 12.04/Asterisk 11 works perfectly. the issue came when i upgraded to 16.04/Asterisk 13 if i reboot on the old disk everything works fine.
I’ve eventually found the issue, at least i believe. It seems that the problem comes from a missing module: res_timing_dahdi
I’m shy on module loading, and didn’t have this module in asterisk 11 but it seems critical for asterisk 13 dahdi
anyone one has an explanation? i’m not sure what is this module for
It is one of several alternative sources of frame rate timing. Wihtout at least one of them, things like PLayback will do nothing, because there is nothing telling them to send the next set of samples.
thanks! i understand the concept of timing and the role of those modules, but apparently between asterisk 11 and asterisk 13 the difference is that in a11 you have a default module and in a13 you have to load a module?
What is also somehow strange is that it affects only dahdi apparently, and there was no problem with SIP channel
Anyway, i’m glad this is solved even if i still feel i’m missing something in understanding the overall behavior
steph