Help for T1 CAS debug

[Jean-Christophe Majchrzak]

Hi,

I'm fighting with a T1 CAS implementation with BTC. So far I've set up only ISDN trunks and I've a lot of difficulties so help is higly appreciated.

T1 config is ok according to Telco requirements. Clock synchronized.

controller T1 0/0/0

framing SF

linecode ami

cablelength long 0db

ds0-group 0 timeslots 1-24 type e&m-wink-start

description LINK to BTC

voice-port 0/0/0:0

description BTC

bearer-cap 3100Hz

If I create a voice translation-rule for called numbers like below it rings and I have voice.

voice translation-rule 2

rule 1 /^$/ /7512199/

But if I want to match my internal devices I need to configure the rule as below, but I have a busy tone.

rule 1 /^.*\(2...$\)/ /751\1/

I don't know how to deal with incoming calls as the Telco seems not sending me any digits. I've atached the debug vpm signal.

Thanks,

[Jean-Christophe Majchrzak]

Adding (in bold)

ds0-group 0 timeslots 1-24 type e&m-wink-start dtmf dnis solved incoming call problem.

But the problem is on the outgoing call side.

Here is the debug vpm signal log.I've dialed 9 for outgoing, then the international prefix and the number.

007716: May 11 00:34:14: htsp_timer_stop3 htsp_setup_req

007717: May 11 00:34:14:  Orig called num:901141227092477

007718: May 11 00:34:14: htsp_process_event: [0/0/0:0(9), EM_ONHOOK, E_HTSP_SETUP_REQ]em_onhook_setup

007719: May 11 00:34:14: em_offhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(9)] set signal state = 0x8

007720: May 11 00:34:14: htsp_process_event: [0/0/0:0(9), EM_BRANCH, EM_EVENT_WINK]

007721: May 11 00:34:14: em_start_timer: 550 ms

007722: May 11 00:34:14: htsp_timer - 550 msec

007723: May 11 00:34:14: htsp_process_event: [0/0/0:0(9), EM_WAIT_WINKUP, E_HTSP_EVENT_TIMER]em_wink_timeout

007724: May 11 00:34:14: em_stop_timers

007725: May 11 00:34:14: htsp_timer_stop2 em_onhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(9)] set signal state = 0x0

007726: May 11 00:34:14: em_start_timer: 400 ms

007727: May 11 00:34:14: htsp_timer - 400 msec

007728: May 11 00:34:14: htsp_process_event: [0/0/0:0(9), EM_GUARD_ALL, E_HTSP_RELEASE_REQ]

007729: May 11 00:34:15: htsp_process_event: [0/0/0:0(9), EM_GUARD_ALL_RLS_REQ, E_HTSP_EVENT_TIMER]em_guard_all_timer

007730: May 11 00:34:15: em_stop_timers

007731: May 11 00:34:15: htsp_timer_stop

007732: May 11 00:34:15: em_stop_timers

007733: May 11 00:34:15: htsp_timer_stop2

007734: May 11 00:34:15: em_start_timer: 3000 ms

007735: May 11 00:34:15: htsp_timer - 3000 msec

007736: May 11 00:34:15: htsp_process_event: [0/0/0:0(9), EM_PARK, E_DSP_SIG_0000]em_park_onhook

007737: May 11 00:34:15: htsp_timer_stop

007738: May 11 00:34:15: htsp_timer_stop2 htsp_report_onhook_sig

JC,

[paolo bevilacqua]

Seems like there is a timing problem, but can't be sure, because there is no millisecods in debug output.

Anyway, if you see no wink coming, that means the CO is not set for wink start, no matter what they claim.

[Jean-Christophe Majchrzak]

I can see incoming wink. And the Telco has confirmed it is a wink / wink config.

Incoming is ok now.

For outgoing calls I've set up the voice port with

voice-port 0/0/0:0

translation-profile incoming TRANSLATION_IN

translation-profile outgoing TRANSLATION_OUT

timing dialout-delay 1000

And also corrected the dial-peer and it works...for 1 call.

But when there are several outgoing calls within I would say 5 seconds there is a busy tone with  DISC CAUSE CODE  44 no requested circuit

example of busy with disc cause 44

014827: May 11 15:37:27.586: htsp_timer_stop3 htsp_setup_req

014828: May 11 15:37:27.586:  Orig called num:01141227093182

014829: May 11 15:37:27.586: htsp_process_event: [0/0/0:0(2), EM_ONHOOK, E_HTSP_SETUP_REQ]em_onhook_setup

014830: May 11 15:37:27.586: em_offhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(2)] set signal state = 0x8

014831: May 11 15:37:27.586: htsp_process_event: [0/0/0:0(2), EM_BRANCH, EM_EVENT_WINK]

014832: May 11 15:37:27.586: em_start_timer: 550 ms

014833: May 11 15:37:27.586: htsp_timer - 550 msec

014834: May 11 15:37:28.138: htsp_process_event: [0/0/0:0(2), EM_WAIT_WINKUP, E_HTSP_EVENT_TIMER]em_wink_timeout

014835: May 11 15:37:28.138: em_stop_timers

014836: May 11 15:37:28.138: htsp_timer_stop2 em_onhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(2)] set signal state = 0x0

014837: May 11 15:37:28.138: em_start_timer: 400 ms

014838: May 11 15:37:28.138: htsp_timer - 400 msec

014839: May 11 15:37:28.138: htsp_process_event: [0/0/0:0(2), EM_GUARD_ALL, E_HTSP_RELEASE_REQ]

014840: May 11 15:37:28.538: htsp_process_event: [0/0/0:0(2), EM_GUARD_ALL_RLS_REQ, E_HTSP_EVENT_TIMER]em_guard_all_timer

014841: May 11 15:37:28.538: em_stop_timers

014842: May 11 15:37:28.538: htsp_timer_stop

014843: May 11 15:37:28.538: em_stop_timers

014844: May 11 15:37:28.538: htsp_timer_stop2

014845: May 11 15:37:28.538: em_start_timer: 3000 ms

014846: May 11 15:37:28.538: htsp_timer - 3000 msec

014847: May 11 15:37:28.538: htsp_process_event: [0/0/0:0(2), EM_PARK, E_DSP_SIG_0000]em_park_onhook

014848: May 11 15:37:28.538: htsp_timer_stop

014849: May 11 15:37:28.538: htsp_timer_stop2 htsp_report_onhook_sig

014850: May 11 15:37:31.982: htsp_timer_stop3 htsp_setup_req

014851: May 11 15:37:31.982:  Orig called num:3022115

014852: May 11 15:37:31.982: htsp_process_event: [0/0/0:0(9), EM_ONHOOK, E_HTSP_SETUP_REQ]em_onhook_setup

014853: May 11 15:37:31.982: em_offhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(9)] set signal state = 0x8

014854: May 11 15:37:31.982: htsp_process_event: [0/0/0:0(9), EM_BRANCH, EM_EVENT_WINK]

014855: May 11 15:37:31.982: em_start_timer: 550 ms

014856: May 11 15:37:31.982: htsp_timer - 550 msec

014857: May 11 15:37:32.534: htsp_process_event: [0/0/0:0(9), EM_WAIT_WINKUP, E_HTSP_EVENT_TIMER]em_wink_timeout

014858: May 11 15:37:32.534: em_stop_timers

014859: May 11 15:37:32.534: htsp_timer_stop2 em_onhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(9)] set signal state = 0x0

014860: May 11 15:37:32.534: em_start_timer: 400 ms

014861: May 11 15:37:32.534: htsp_timer - 400 msec

014862: May 11 15:37:32.534: htsp_process_event: [0/0/0:0(9), EM_GUARD_ALL, E_HTSP_RELEASE_REQ]

014863: May 11 15:37:32.934: htsp_process_event: [0/0/0:0(9), EM_GUARD_ALL_RLS_REQ, E_HTSP_EVENT_TIMER]em_guard_all_timer

014864: May 11 15:37:32.934: em_stop_timers

014865: May 11 15:37:32.934: htsp_timer_stop

014866: May 11 15:37:32.934: em_stop_timers

014867: May 11 15:37:32.934: htsp_timer_stop2

014868: May 11 15:37:32.934: em_start_timer: 3000 ms

014869: May 11 15:37:32.934: htsp_timer - 3000 msec

014870: May 11 15:37:32.934: htsp_process_event: [0/0/0:0(9), EM_PARK, E_DSP_SIG_0000]em_park_onhook

014871: May 11 15:37:32.934: htsp_timer_stop

014872: May 11 15:37:32.934: htsp_timer_stop2 htsp_report_onhook_sig

014873: May 11 15:37:36.658: htsp_timer_stop3 htsp_setup_req

014874: May 11 15:37:36.658:  Orig called num:5655569

014875: May 11 15:37:36.658: htsp_process_event: [0/0/0:0(3), EM_ONHOOK, E_HTSP_SETUP_REQ]em_onhook_setup

014876: May 11 15:37:36.658: em_offhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(3)] set signal state = 0x8

014877: May 11 15:37:36.658: htsp_process_event: [0/0/0:0(3), EM_BRANCH, EM_EVENT_WINK]

014878: May 11 15:37:36.658: em_start_timer: 550 ms

014879: May 11 15:37:36.658: htsp_timer - 550 msec

014880: May 11 15:37:37.210: htsp_process_event: [0/0/0:0(3), EM_WAIT_WINKUP, E_HTSP_EVENT_TIMER]em_wink_timeout

What is the reason ?

thanks,

[Jean-Christophe Majchrzak]

To add more precision here is the call output that fails

018731: May 11 16:10:38.859: htsp_timer_stop3 htsp_setup_req

018732: May 11 16:10:38.859:  Orig called num:3022131

018733: May 11 16:10:38.859: htsp_process_event: [0/0/0:0(8), EM_ONHOOK, E_HTSP_SETUP_REQ]em_onhook_setup

018734: May 11 16:10:38.859: em_offhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(8)] set signal state = 0x8

018735: May 11 16:10:38.859: htsp_process_event: [0/0/0:0(8), EM_BRANCH, EM_EVENT_WINK]

018736: May 11 16:10:38.859: em_start_timer: 550 ms

018737: May 11 16:10:38.859: htsp_timer - 550 msec

018738: May 11 16:10:39.411: htsp_process_event: [0/0/0:0(8), EM_WAIT_WINKUP, E_HTSP_EVENT_TIMER]em_wink_timeout

018739: May 11 16:10:39.411: em_stop_timers

018740: May 11 16:10:39.411: htsp_timer_stop2 em_onhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(8)] set signal state = 0x0

018741: May 11 16:10:39.411: em_start_timer: 400 ms

018742: May 11 16:10:39.411: htsp_timer - 400 msec

018743: May 11 16:10:39.411: htsp_process_event: [0/0/0:0(8), EM_GUARD_ALL, E_HTSP_RELEASE_REQ]

018744: May 11 16:10:39.811: htsp_process_event: [0/0/0:0(8), EM_GUARD_ALL_RLS_REQ, E_HTSP_EVENT_TIMER]em_guard_all_timer

018745: May 11 16:10:39.811: em_stop_timers

018746: May 11 16:10:39.811: htsp_timer_stop

018747: May 11 16:10:39.811: em_stop_timers

018748: May 11 16:10:39.811: htsp_timer_stop2

018749: May 11 16:10:39.811: em_start_timer: 3000 ms

018750: May 11 16:10:39.811: htsp_timer - 3000 msec

018751: May 11 16:10:39.811: htsp_process_event: [0/0/0:0(8), EM_PARK, E_DSP_SIG_0000]em_park_onhook

018752: May 11 16:10:39.811: htsp_timer_stop

018753: May 11 16:10:39.811: htsp_timer_stop2 htsp_report_onhook_sightsp_call_service_msghtsp_call_service_msg not EFXS (1)

018754: May 11 16:10:41.023: htsp_process_event: [0/0/0:0(21), EM_CONNECT, E_HTSP_VOICE_CUT_THROUGH]htsp_call_service_msghtsp_call_service_msg not EFXS (1)htsp_call_service_msghtsp_call_service_msg not EFXS (1)

[paolo bevilacqua · Accepted solution]

As indicated above, wink timeout, indicates telco problem - no matter what they claim.

018738: May 11 16:10:39.411: htsp_process_event: [0/0/0:0(8), EM_WAIT_WINKUP, E_HTSP_EVENT_TIMER]em_wink_timeout

[Jean-Christophe Majchrzak]

Thanks.

But sometimes it works for outgoing calls, sometimes not.

So it may be a Timer problem ? Can I adjust it on my side or on their side ?

[Jean-Christophe Majchrzak]

Even with increased "timing wait-wink 1100" under voice-port it happens sometimes again.

021175: May 11 17:35:39.382: htsp_timer_stop3 htsp_setup_req

021176: May 11 17:35:39.382:  Orig called num:3022131

021177: May 11 17:35:39.382: htsp_process_event: [0/0/0:0(12), EM_ONHOOK, E_HTSP_SETUP_REQ]em_onhook_setup

021178: May 11 17:35:39.382: em_offhook (0)vnm_dsp_set_sig_state:[recEive and transMit0/0/0:0(12)] set signal state = 0x8

021179: May 11 17:35:39.382: htsp_process_event: [0/0/0:0(12), EM_BRANCH, EM_EVENT_WINK]

021180: May 11 17:35:39.382: em_start_timer: 1100 ms

021181: May 11 17:35:39.382: htsp_timer - 1100 msec

021182: May 11 17:35:40.482: htsp_process_event: [0/0/0:0(12), EM_WAIT_WINKUP, E_HTSP_EVENT_TIMER]em_wink_timeout

021183: May 11 17:35:40.482: em_stop_timers

I'll try increasing values...And let you know.

Edit : With wait-wink set at its maximum 6500 ms same result. So definitely like Paolo Bevilacqua said : telco problem...

[Jean-Christophe Majchrzak]

So for channels 1 to 12 included , outgoing calls always fail with Wink timeout.

With channels 13 to 24 it always work.

What are the possibilities if the Telco doe snothing to help me ?

Can I create 2 groups of channels, 1 for incoming and 1 for outgoing calls ?

[paolo bevilacqua]

Yes, you can create multiple ds0- groups.

If you tell telco that lower channels are behaving  differently than the high ones, eventually they will, slowly and reluctantly, look and fix the issue.

Thank you for the nice rating and good luck!

[Jean-Christophe Majchrzak]

Finally problem solved by asking Telco to change the lower channels behaviour.

As Telco said "Trunks are currently configured as 12 incoming & 12 outgoing"

So now they are configured as 24 incoming and outgoing.

The rating is normal because you've found the root cause that has helped me to debug this strange behaviour.

Thanks for help.