Problem with rotary phone

Debian 11, latest asterisk from Debian repository.
I have connected to a TDM400P an old rotary Phone.
The problem: I want to dial 600


; Test dell'eco
exten => 600,1,NoOp()
same => n,Set(CDR(mycustomfield)=coffee)
same => n,Verbose(I need some more ${CDR(mycustomfield)})
same => n(open),Answer()
same => n,Playback(demo-echotest) ; Let them know what
same => n,Echo()                  ; Do the echo test
same => n,Playback(demo-echodone) ; Let them know it
same => n(close),Playback(go-away2) ; Let them know it
same => n,Hangup()

But after instead of “compose” 600 the composing finiish at 6 or 60 and I heard free tone!

On console I see this

This is the chan_dahdi.conf


[trunkgroups]
[channels]
language=it
context=local
switchtype=euroisdn
overlapdial=yes
signalling=bri_net_ptmp
usecallerid=yes
hidecallerid=no
callwaiting=yes
usecallingpres=yes
callwaitingcallerid=yes
threewaycalling=yes
transfer=yes    ;se usi nt ptmp metti no
canpark=yes
cancallforward=yes
callreturn=yes
context=local
echocancel=yes
channel => 1,2,4,5,7,8,10,11
echocancelwhenbridged=yes
group=1
callgroup=1
pickupgroup=1
immediate=no
pulsedial=yes
busycount=6
busydetect=yes
#include /etc/asterisk/dahdi-channels.conf

You haven’t include the included file.

You haven’t included the complete dialplan, as it appears, from the log, that 64 is valid extension in the dialplan, even if no-one is parked there. Having extensions that were variable in length really wasn’t something that was done in the era of pulse dial phones.

You might want to have a look at:

Given your numbering plan, I suspect you are being caught out by matchdigit_timeout.

When providing logs, please provide full logs, wither a verbosity of 5. Pure debug logs don’t have the necessary context.

If 64 was 60, the dial speed may be wrong.

I have tried to set the timeouts, but nothing change


firstdigit_timeout=16000
interdigit_timeout=10000
matchdigit_timeout=8000

On console I see

[Dec 13 18:29:51]     -- Starting simple switch on 'DAHDI/13-1'
[Dec 13 18:29:54]     -- Hanging up on 'DAHDI/13-1'
[Dec 13 18:29:54]     -- Hungup 'DAHDI/13-1'
[Dec 13 18:29:56]     -- Starting simple switch on 'DAHDI/13-1'
[Dec 13 18:30:00]     -- Hanging up on 'DAHDI/13-1'
[Dec 13 18:30:00]     -- Hungup 'DAHDI/13-1'
[Dec 13 18:30:00] WARNING[2387]: chan_dahdi.c:5086 dahdi_set_hook: DAHDI hook failed returned -1 (trying 1): Device or resource busy
[Dec 13 18:30:03]     -- Starting simple switch on 'DAHDI/13-1'
[Dec 13 18:30:05]     -- Hanging up on 'DAHDI/13-1'
[Dec 13 18:30:05]     -- Hungup 'DAHDI/13-1'
[Dec 13 18:30:05] WARNING[2387]: chan_dahdi.c:5086 dahdi_set_hook: DAHDI hook failed returned -1 (trying 1): Device or resource busy
[Dec 13 18:30:08]     -- Starting simple switch on 'DAHDI/13-1'
[Dec 13 18:30:10]     -- Hanging up on 'DAHDI/13-1'
[Dec 13 18:30:10]     -- Hungup 'DAHDI/13-1'
[Dec 13 18:30:11]     -- Starting simple switch on 'DAHDI/13-1'
[Dec 13 18:30:18]     -- Hanging up on 'DAHDI/13-1'
[Dec 13 18:30:18]     -- Hungup 'DAHDI/13-1'

Now when I compose 600

sometimes after 6 “close” sic!
sometimes after 60

and return the line free tone!

Testing the rotary phone on my telco-router, and works perfect

You need the full log, which has the debug, warning, and verbose lines in the correct relationship to each other.

As noted, 60, not 64 was seen.

You appear to have a pattern in your dialplan that is matching 6X, not just one for 600.

1 Like

I have try a very simple dialplan

[from-dahdi]
exten => 1000,1,Dial(SIP/1001,10,t,m)
exten => 1000,2,Voicemail(1001@interni)
exten => 1000,3,Hangup

exten => 1006,1,Dial(dahdi/g15,10,t,m)
exten => 1006,2,Voicemail(1006@interni)
exten => 1006,3,Hangup

exten => 7500,1,VoicemailMain(@interni)

exten => 600,1,Answer()
exten => 600,2,Playback(demo-echotest) ; Let them know what
exten => 600,3,Echo()                  ; Do the echo test
exten => 600,4,Playback(demo-echodone) ; Let them know it 
exten => 600,5,Hangup()

Try increase the debug

core set debug 5
core set verbose 5

This is the result


[Dec 14 13:02:08] DEBUG[2695]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:08] DEBUG[2696]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:08] DEBUG[2690]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 3
[Dec 14 13:02:08] DEBUG[2690]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 4
[Dec 14 13:02:09] DEBUG[2694]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:09] DEBUG[2690]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 2
[Dec 14 13:02:09] DEBUG[2692]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:09] DEBUG[2693]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:09] DEBUG[2690]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 0
[Dec 14 13:02:09] DEBUG[2690]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 1
[Dec 14 13:02:19] DEBUG[2729]: res_pjsip_registrar.c:1286 check_expiration_thread: Woke up at 1671019339  Interval: 30
[Dec 14 13:02:19] DEBUG[2729]: res_pjsip_registrar.c:1293 check_expiration_thread: Expiring 0 contacts
[Dec 14 13:02:31] DEBUG[2751]: chan_dahdi.c:11745 do_monitor: Monitor doohicky got event Ring/Answered on channel 14
[Dec 14 13:02:31] DEBUG[2751]: sig_analog.c:3683 analog_handle_init_event: channel (14) - signaling (2) - event (ANALOG_EVENT_RINGOFFHOOK)
[Dec 14 13:02:31] DEBUG[2751][C-00000001]: stasis.c:575 stasis_topic_create_with_detail: Creating topic. name: channel:1671019351.0, detail: 
[Dec 14 13:02:31] DEBUG[2751][C-00000001]: stasis.c:609 stasis_topic_create_with_detail: Topic 'channel:1671019351.0': 0x7f11fc001600 created
[Dec 14 13:02:31] DEBUG[2751][C-00000001]: stasis.c:575 stasis_topic_create_with_detail: Creating topic. name: cache:4/channel:1671019351.0, detail: 
[Dec 14 13:02:31] DEBUG[2751][C-00000001]: stasis.c:609 stasis_topic_create_with_detail: Topic 'cache:4/channel:1671019351.0': 0x7f11fc004060 created
[Dec 14 13:02:31] DEBUG[2751][C-00000001]: channel.c:989 __ast_channel_alloc_ap: Channel 0x7f11fc0018b0 'DAHDI/14-1' allocated
[Dec 14 13:02:31] DEBUG[2751][C-00000001]: dsp.c:507 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Dec 14 13:02:31] DEBUG[2751][C-00000001]: dsp.c:507 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Dec 14 13:02:31] DEBUG[2702]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for DAHDI - 14
[Dec 14 13:02:31] DEBUG[2702]: devicestate.c:466 do_state_change: Changing state for DAHDI/14 - state 2 (In use)
[Dec 14 13:02:31] DEBUG[2763]: sig_analog.c:1736 __analog_ss_thread: __analog_ss_thread 14
    -- Starting simple switch on 'DAHDI/14-1'
[Dec 14 13:02:33] DEBUG[2763][C-00000001]: sig_analog.c:3561 analog_exception: analog_exception 14
[Dec 14 13:02:33] DEBUG[2763][C-00000001]: sig_analog.c:3653 analog_exception: Exception on 36, channel 14
[Dec 14 13:02:33] DEBUG[2763][C-00000001]: sig_analog.c:2698 __analog_handle_event: __analog_handle_event 14
[Dec 14 13:02:33] DEBUG[2763][C-00000001]: sig_analog.c:2725 __analog_handle_event: Got event ANALOG_EVENT_PULSE_START(10) on channel 14 (index 0)
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:3561 analog_exception: analog_exception 14
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:3653 analog_exception: Exception on 36, channel 14
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:2698 __analog_handle_event: __analog_handle_event 14
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:2725 __analog_handle_event: Got event UNKNOWN/OTHER(65588) on channel 14 (index 0)
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:2729 __analog_handle_event: Detected pulse digit '4'
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:1568 analog_handle_dtmf: End DTMF digit: 0x34 '4' on DAHDI/14-1
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: chan_dahdi.c:1654 my_handle_dtmf: End DTMF digit: 0x34 '4' on DAHDI/14-1
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:2112 __analog_ss_thread: waitfordigit returned '4' (52), timeout = 0
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:2356 __analog_ss_thread: Can't match 4 from '1008' in context from-dahdi
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: channel.c:2565 ast_hangup: Channel 0x7f11fc0018b0 'DAHDI/14-1' hanging up.  Refs: 2
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: chan_dahdi.c:6001 dahdi_hangup: dahdi_hangup(DAHDI/14-1)
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:1256 analog_hangup: analog_hangup 14
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:1278 analog_hangup: Hangup: channel: 14 index = 0, normal = 1, callwait = 0, thirdcall = 0
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: chan_dahdi.c:6594 dahdi_setoption: Set option TONE VERIFY, mode: OFF(0) on DAHDI/14-1
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: chan_dahdi.c:6604 dahdi_setoption: Set option TDD MODE, value: OFF(0) on DAHDI/14-1
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: sig_analog.c:764 analog_update_conf: Updated conferencing on 14, with 0 conference users
    -- Hanging up on 'DAHDI/14-1'
    -- Hungup 'DAHDI/14-1'
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: channel.c:2211 ast_channel_destructor: Channel 0x7f11fc0018b0 'DAHDI/14-1' destroying
[Dec 14 13:02:34] DEBUG[2710]: cdr.c:1468 cdr_object_finalize: Finalized CDR for DAHDI/14-1 - start 1671019351.146574 answer 0.000000 end 1671019354.019709 dur 2.873 bill 1671019354.019 dispo FAILED
[Dec 14 13:02:34] DEBUG[2710]: cdr.c:3541 post_cdr: Skipping CDR for DAHDI/14-1 since we weren't answered
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: stasis.c:437 topic_dtor: Destroying topic. name: cache:4/channel:1671019351.0, detail: 
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: stasis.c:446 topic_dtor: Topic 'cache:4/channel:1671019351.0': 0x7f11fc004060 destroyed
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: stasis.c:437 topic_dtor: Destroying topic. name: channel:1671019351.0, detail: 
[Dec 14 13:02:34] DEBUG[2763][C-00000001]: stasis.c:446 topic_dtor: Topic 'channel:1671019351.0': 0x7f11fc001600 destroyed
[Dec 14 13:02:34] DEBUG[2702]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for DAHDI - 14
[Dec 14 13:02:34] DEBUG[2702]: devicestate.c:466 do_state_change: Changing state for DAHDI/14 - state 0 (Unknown)
[Dec 14 13:02:34] DEBUG[2751]: chan_dahdi.c:11745 do_monitor: Monitor doohicky got event Hook Transition Complete on channel 14
[Dec 14 13:02:34] DEBUG[2751]: sig_analog.c:3683 analog_handle_init_event: channel (14) - signaling (2) - event (ANALOG_EVENT_HOOKCOMPLETE)
[Dec 14 13:02:35] DEBUG[2751]: chan_dahdi.c:11745 do_monitor: Monitor doohicky got event Pulse Start on channel 14
[Dec 14 13:02:35] DEBUG[2751]: sig_analog.c:3683 analog_handle_init_event: channel (14) - signaling (2) - event (ANALOG_EVENT_PULSE_START)
[Dec 14 13:02:36] DEBUG[2751]: chan_dahdi.c:11745 do_monitor: Monitor doohicky got event Event 65591 on channel 14
[Dec 14 13:02:36] DEBUG[2751]: sig_analog.c:3683 analog_handle_init_event: channel (14) - signaling (2) - event (UNKNOWN/OTHER)
[Dec 14 13:02:37] DEBUG[2751]: chan_dahdi.c:11745 do_monitor: Monitor doohicky got event Pulse Start on channel 14
[Dec 14 13:02:37] DEBUG[2751]: sig_analog.c:3683 analog_handle_init_event: channel (14) - signaling (2) - event (ANALOG_EVENT_PULSE_START)
[Dec 14 13:02:38] DEBUG[2751]: chan_dahdi.c:11745 do_monitor: Monitor doohicky got event Event 65591 on channel 14
[Dec 14 13:02:38] DEBUG[2751]: sig_analog.c:3683 analog_handle_init_event: channel (14) - signaling (2) - event (UNKNOWN/OTHER)
[Dec 14 13:02:41] DEBUG[2751]: chan_dahdi.c:11745 do_monitor: Monitor doohicky got event On hook on channel 14
[Dec 14 13:02:41] DEBUG[2751]: sig_analog.c:3683 analog_handle_init_event: channel (14) - signaling (2) - event (ANALOG_EVENT_ONHOOK)
[Dec 14 13:02:49] DEBUG[2719]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:49] DEBUG[2717]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:49] DEBUG[2718]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:49] DEBUG[2712]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 9
[Dec 14 13:02:49] DEBUG[2712]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 7
[Dec 14 13:02:49] DEBUG[2712]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 8
[Dec 14 13:02:49] DEBUG[2729]: res_pjsip_registrar.c:1286 check_expiration_thread: Woke up at 1671019369  Interval: 30
[Dec 14 13:02:49] DEBUG[2729]: res_pjsip_registrar.c:1293 check_expiration_thread: Expiring 0 contacts
[Dec 14 13:02:49] DEBUG[2720]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:49] DEBUG[2691]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 10
[Dec 14 13:02:49] DEBUG[2715]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:49] DEBUG[2716]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying.
[Dec 14 13:02:49] DEBUG[2712]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 5
[Dec 14 13:02:49] DEBUG[2712]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 6

Very strange, I remind when I bought the phone last year works fine without any special configuration

Sometimes another error…

[Dec 14 13:17:29] WARNING[3190]: chan_dahdi.c:4932 dahdi_set_hook: DAHDI hook failed returned -1 (trying 1): Device or resource busy
    -- Starting simple switch on 'DAHDI/13-1'
    -- Hanging up on 'DAHDI/13-1'
    -- Hungup 'DAHDI/13-1'

I presume the card is old or second hand, as, for a supported card, the advice would be to get support through Sangoma’s commercial web site.

You seem to be getting a lot of bogus 4s. I don’t know if the pulse counts are done in hardware or software, but in the former case, the problem is in hardware. You probably need to put an oscilloscope on pair from the phone and see if the pulse timing and currents are in specification.

I assume if you are playing with rotary dial phones there is a good chance that you have test equipment or the ability to improvise it.

I have ordered a more recent card pci-e fxs.
But very strange, this card works at least the latest year…

This is the chan_dahdi.conf, if interested

[trunkgroups]
[channels]
language=it
context=from-dahdi
switchtype=euroisdn
overlapdial=yes
signalling=bri_net_ptmp
usecallerid=yes
hidecallerid=no
callwaiting=yes
usecallingpres=yes
callwaitingcallerid=yes
threewaycalling=yes
transfer=no
canpark=yes
cancallforward=yes
callreturn=yes
echocancel=yes
channel => 1,2,4,5,7,8,10,11
echocancelwhenbridged=yes
group=1
callgroup=1
pickupgroup=1
immediate=no
busycount=6
busydetect=yes
pulsedial=yes
#include /etc/asterisk/dahdi-channels.conf

That’s incomplete, as you need to see the included file as well for some of the critical settings.

dahdi-channels.conf

; Autogenerated by /sbin/dahdi_genconf on Tue Dec 13 16:47:36 2022
; If you edit this file and execute /sbin/dahdi_genconf again,
; your manual changes will be LOST.
; Dahdi Channels Configurations (chan_dahdi.conf)
;
; This is not intended to be a complete chan_dahdi.conf. Rather, it is intended
; to be #include-d by /etc/chan_dahdi.conf that will include the global settings
;

; Span 1: B4/0/1 "B4XXP (PCI) Card 0 Span 1" AMI/CCS RED 
group=0,11
context=from-dahdi
switchtype = euroisdn
signalling = bri_net_ptmp
channel => 1-2

; Span 2: B4/0/2 "B4XXP (PCI) Card 0 Span 2" AMI/CCS RED 
group=0,12
context=from-dahdi
switchtype = euroisdn
signalling = bri_net_ptmp
channel => 4-5

; Span 3: B4/0/3 "B4XXP (PCI) Card 0 Span 3" AMI/CCS RED 
group=0,13
context=from-dahdi
switchtype = euroisdn
signalling = bri_net_ptmp
channel => 7-8

; Span 4: B4/0/4 "B4XXP (PCI) Card 0 Span 4" AMI/CCS RED 
group=0,14
context=from-dahdi
switchtype = euroisdn
signalling = bri_net_ptmp
channel => 10-11

; Span 5: WCTDM/4 "Wildcard TDM400P REV E/F Board 5" (MASTER) 
;;; line="13 WCTDM/4/0 FXOKS"
signalling=fxo_ks
callerid="Telefono analogico 1" <1007>
mailbox=1007
group=0,15
context=from-dahdi
channel => 13

;;; line="14 WCTDM/4/1 FXOKS"
signalling=fxo_ks
callerid="Telefono analogico 2" <1008>
mailbox=1007
group=0,16
context=from-dahdi
channel => 14

;;; line="16 WCTDM/4/3 FXSKS"
signalling=fxs_ks
callerid=asreceived
group=0
context=from-dahdi
channel => 16

It appears that DAHDI hasn’t supported that card for a long time! What version of DAHDI are you using?

Dahdi git+old sources+patch for wctdm module “rebirth”
If you want i can paste my slackbuild.

p.s=i’ve solved

Solution found. I put another rotary phone and…works!
So was probably some hardware problem or on other rotary phone (broken? :unamused: )
But…why the old phone works with TELCO line?

EDIT1: i found the “solution”
Was the number composed too fast!
The other rotary phone has the “circle” more slow than this, if i make the number slowly…all works.

Depending on the make/break ratio of the dial, that may affect your success.

You can use the Asterisk dial pulse speed test[1] to measure your dials and see what the speeds and make/break ratio are. If it reports “FAST”, then that may explain it. I typically don’t have issues with dials that are within 1 or 2 pps of the desired target range.

The linked resource also adds the wctdm driver back to DAHDI (in addition to making the dial pulse speed test possible).

[1] phreakscript/res_dialpulse.c at master · InterLinked1/phreakscript · GitHub

1 Like

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.