Cisco 6901 и астериск, звонок начинается спустя 10 сек.

[sp1er]

Всем привет!

Я понимаю что это проблема не астериска, а конкретно проблема cisco 69xx серии, так же пробовал на 6921, может кто сталкивался и нашел решение данной проблемы.

На IP Phone 6901 с прошивкой SIP: SIP6901.9-3-1-SR2-3, когда я набираю любой номер, то Dial начинается через 10 секунд (Видно в консоли asterisk). Хотя в диалплане описано отправлять звонки к примеру на ХХХ сразу.

<DIALTEMPLATE>
<TEMPLATE MATCH="1.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="2.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="3.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="4.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="5.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="6.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="7.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="8.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="9.." Timeout="0" /> <!-- Corporate Dial plan-->
<TEMPLATE MATCH="00.*" Timeout="6" /> <!-- Anything else -->
<TEMPLATE MATCH="*" Timeout="15" /> <!-- Anything else -->
</DIALTEMPLATE>

С таким же диалпланом на серии 79** проблем нет. Конфиг приатачил

[ded]

А Вы можете убедиться, что ваш dialplan.xml телефон Cisco 6901 подгружает?
tcpdump host ip_addr_ip_phone
и перезагрузить. Внимательно смотрим какие конфиги он забирает...

[sp1er]

Да подгружает, такое ощущение что они его просто игнорируют.

Код: выделить все

02:53 debian0 atftpd[8199]: Serving dialplan.xml to 192.168.65.239:1024

В логах циски так же видно что она его получает.

Код: выделить все

2000/01/01 00:01:05:911   Succeed to get SIP6901.9-3-1-SR2-3.loads
2000/01/01 00:01:06:059   Succeed to get dialplan.xml


Я пробовал даже убрать в конфиге путь к диалплану, циска нормально грузится и работает так же как и с диал планом, через 10 секунд выдает звонок. Такое ощущение, что она его просто игнорирует.

[ded]

Succeed to get dialplan.xml - этого мало. Посмотрите в console logs, может быть там увидите, что валидатор XML в телефоне по каким-то причинам отбрасывает его - ошибки? Которые аппараты серии 79ХХ игнорируют.
И я бы посмотрел в sip debug таких звонков, и увидел, что высылает то Invite телефон сразу, как положено по dialplan.xml, а проблема совсем в другом.

[sp1er]

По логу не видно чтоб ругался на dialplan.xml(лог под спойлером). Проверил дебаг в asterisk Invite отправляет не сразу, а через 10 сек

[Показать] Спойлер: log

Код: выделить все


00:00:30:223   [TI] NMM: Build contains neither a TIU or UIU/TUIU.

00:00:30:248   [TI] DSPALLOC: AER instance 1, max_tail = 60 ms, usage = ( HS  HeS  GL_HS  GL_HeS )

00:00:30:248   [TI] DSPALLOC: AER instance 0, max_tail = 200 ms, usage = ( HS  HeS  HF  GL_HS  GL_HeS )

00:00:30:261   [TI] DIM: 0:*, Download requested 3 channels, max is 2 will use 2

00:00:31:026   [TI] DIM: 0:*,Writing 0x6a001400 @ 0x100

00:00:31:140   [TI] DSPA: DSP 0,Image 0:Download done!

00:00:31:141   [TI] NMM: Starting Activate Timer

00:00:31:344   [TI] CCU: ccup_proc_configure_ipp, headset_port=2 hs_prof = 0, hes_prof = 1, hf_prof = 2, gl_hs_prof = 3, gl_hes_prof = 4, rg_prof = 10, ext_bt_prof = 12, lcd default row = 4

00:00:31:346   [TI] CCU: ccup_proc_configure_ipp, hs_prof2 = 5, hes_prof2 = 6, hf_prof2 = 7, gl_hs_prof2 = 8, gl_hes_prof2 = 9, rg_prof2 = 11, ext_bt_prof2 = 13,

00:00:31:347   [TI] CCU: ccup_proc_configure_ipp, hs_prof3 = 14, hes_prof3 = 15, hf_prof3 = 16, gl_hs_prof3 = 17, gl_hes_prof3 = 18,

00:00:31:348   [TI] NMM: 0, Switched CAS, FXS Loop Start

00:00:31:349   [TI] NMM: 0, Set Channel State UNCONFIGURED Done (SUCCESS)

00:00:31:351   [TI] NMM: 0, Channel Config Done (SUCCESS)

00:00:31:356   [TI] NMM: 0, Set Channel State NORMAL Done (SUCCESS)

00:00:31:356   [TI] NMM: 1, Switched CAS, FXS Loop Start

00:00:31:357   [TI] NMM: 1, Set Channel State UNCONFIGURED Done (SUCCESS)

00:00:31:357   [TI] NMM: 1, Channel Config Done (SUCCESS)

00:00:31:359   [TI] NMM: 1, Set Channel State NORMAL Done (SUCCESS)

00:00:31:360 f [FOS] Send Msg Failed! msgQ  0, ErrorNo (8)


00:00:33:087 x [secC] secClient_msgSend send fail err 9 Bad file descriptor

00:00:33:188 f [XCCU]  Report DSP fail, retry...

00:00:33:190 f [MMI]
: MCU ready !! 

00:00:33:229 w [PROVISION] dst_init() Create DST timer successfully, dstTmr.magic=14

00:00:33:239 x [EW] PID_EW_END_OF_RANGE_OF_SEQUENCE : 200

00:00:33:284 x [unreg] unreg_syncUnregisterAlarmFromFlash() read /var/voice_conf/device_unregister_xml error

00:00:33:614 x [SIP-Stack] cpr_linux_sbrk: could not provide 4096 bytes more memory

00:00:33:615 x [SIP-Stack] cpr_linux_sbrk: could not provide 4096 bytes more memory

00:00:33:615 x [SIP-Stack] ERROR: malloc 1306 bytes failed, pc=0x2abcbc98

00:00:33:619 % [cent] State INIT --> NO_NETWORK

00:00:35:623 % [cent] FSM event(LINK_UP) / state(NO_NETWORK) / cause(0)

00:00:35:624 % [cent] FSM event(PC_LINK_UP) / state(NO_NETWORK) / cause(0)

00:00:35:625 x [switchConfig] Disable SpanToPc fail

00:00:35:630 x [switchConfig] set config sussceful!

00:00:39:702 % [cent] FSM event(PALS_LINKUP_COMPLETED) / state(NO_NETWORK) / cause(0)

00:00:39:703 % [cent] State NO_NETWORK --> CONFIGURING_VLAN

00:00:59:820 % [cent] FSM event(NET_POLICY_CHANGE) / state(CONFIGURING_VLAN) / cause(0)

00:00:59:842 % [cent] State CONFIGURING_VLAN --> CONFIGURING_IP

00:00:59:930 % [cent] FSM event(DHCP_RESPONSE) / state(CONFIGURING_IP) / cause(12)

00:01:02:941 % [cent] FSM event(DHCP_RESPONSE) / state(CONFIGURING_IP) / cause(5)

00:01:04:255 % [cent] FSM event(CONFIG_DYNAMIC_IP_OK) / state(CONFIGURING_IP) / cause(0)

00:01:04:255 % [cent] State CONFIGURING_IP --> CONFIGURING_TFTP

00:01:04:258 % [cent] FSM event(CONFIG_TFTP_OK) / state(CONFIGURING_TFTP) / cause(0)

00:01:04:259 % [cent] State CONFIGURING_TFTP --> PROVISIONING

00:01:04:269 w [SUU] tftp Command = tftp -g -r CTLSEP34BDC82DD663.tlv 192.168.64.2 69 -l /var/prov/CTLSEP34BDC82DD663.tlv -t 6 -s 524288 -q 0

00:01:04:279 f [SUU] Tftp Server Says: File not found

00:01:04:366 f [SUU] tftp download fail, result = 3

2000/01/01 00:01:04:368 1 File Not Found : CTLSEP34BDC82DD663.tlv


2000/01/01 00:01:04:369 1 No CTL installed


2000/01/01 00:01:04:369 1 Non-secure Mode Provision


00:01:04:371 w [SUU] tftp Command = tftp -g -r SEP34BDC82DD663.cnf.xml 192.168.64.2 69 -l /var/prov/SEP34BDC82DD663.cnf.xml -t 6 -s 524288 -q 0

2000/01/01 00:01:04:394 1 Succeed to get SEP34BDC82DD663.cnf.xml


00:01:04:398 f [PROVISION] reset secure mode fail. PROV BUF.

00:01:04:899 w [PROVISION] characterData()  Is SRST Security -- false...

00:01:05:911 w [PROVISION] characterData()  Device security mode is 1...

00:01:05:978 f [PROVISION] saveCucmArrayToConfig() i=0,  szBuf=192.168.64.2

00:01:05:978 f [PROVISION] saveCucmArrayToConfig() i=0,  szBuf=Unicast

00:01:05:979 f [PROVISION] saveCucmArrayToConfig() i=1,  szBuf=0.0.0.0

00:01:05:979 f [PROVISION] saveCucmArrayToConfig() i=1,  szBuf=Directed Broadcast

00:01:05:983 x [PROVISION] provCfg_checkLocalCfgFile(): Failed to open RAM local-saved-cfg file /var/provCfgBak/SEPLocalCfgFile.cnf.xml.enc

00:01:06:970 f [PROVISION] Fail to get local information.

00:01:06:971 w [PROVISION]  Start downloading .loads file.

00:01:06:972 w [SUU] tftp Command = tftp -g -r SIP6901.9-2-2-2.loads 192.168.64.2 69 -l /var/prov/SIP6901.9-2-2-2.loads -t 6 -s 524288 -q 96

2000/01/01 00:01:06:980 1 Succeed to get SIP6901.9-2-2-2.loads


00:01:06:981 w [PROVISION] provCfg_checkLoadsFile():  /var/prov/SIP6901.9-2-2-2.loads

00:01:07:135 w [PROVISION] No need to download tzData file.

00:01:07:140 w [PROVISION] processLoadsHandlerResp(), do provision according to new flow.

00:01:07:142 w [SUU] tftp Command = tftp -g -r dialplan.xml 192.168.64.2 69 -l /var/prov/dialplan.xml -t 6 -s 524288 -q 96

2000/01/01 00:01:07:149 1 Succeed to get dialplan.xml


00:01:07:248 % [cent] FSM event(PROV_CFG_CHANGE) / state(PROVISIONING) / cause(0)

00:01:07:341 x [cent] Enter processSSHInfo().

00:01:08:235 % [cent] State PROVISIONING --> REGISTERING

00:01:08:237 g [sipCC] sip_callclient_startRegister()

00:01:08:237 g [sipCC] sip_callclient_startRegister() starting SIP Stack

00:01:08:241 g [sipCC] sipCCMain() SIP start register

00:01:08:241 g [sipCC] sipCCMain() SIP start sipMainStart register

00:01:08:245 x [EW] ewCheckCMCfg(). EW PSP

00:01:08:245 x [EW] ewCheckCMCfg(). EW Phone On Time

00:01:08:246 x [EW] ewCheckCMCfg(). EW Phone Off Time

00:01:08:247 x [EW] ewCheckCMCfg(). EW Phone Off Idle Timeout 20

00:01:08:247 x [EW] ewTranslate2PersistentCfg().Save Phone Off Idle Timeout CFG (temp) Failed

00:01:09:499 x [SIP-Stack] cprSetMessageQueueThread: Invalid input

00:01:09:503 x [SIP] g_deviceSecurityMode=1

00:01:09:505 x [SIP] SRST port =5060, srst_sipport=5060,  SRST_SEC_LEVEL = 0 secMode 1

00:01:09:846 x [SIP-Stack] SIP : sip_transport_setup_cc_conn : Admin has not configured a valid cucm for cucm index=SECONDARY_CCM=1.

00:01:09:847 x [SIP-Stack] SIP : sip_transport_setup_cc_conn : Admin has not configured a valid cucm for cucm index=TERTIARY_CCM=2.

00:01:10:071 x [SIP-Stack] SIPCC-FUNC_CALL: sip_transport_setup_cc_conn: Error: dnsGetHostByName() returned error:%s returned error.

00:01:10:072 x [SIP-Stack] sip_regmgr_setup_cc_conns: NO VALID STANDBY CALL CONTROL AVAILABLE!

00:01:10:466 g [sipCC] sip_callclient_delLine() Del line, id=1

00:01:10:469 % [cent] FSM event(UNREGISTERED) / state(REGISTERING) / cause(0)

00:01:10:482 x [SIP] platSetUnregReason() set unreg reason to 25

00:01:10:531 w [PROVISION] setDateTime() get CFG value fail, set GMT time to system

11:37:18:541 g [sipCC] sip_callclient_inService() cucm_mode 0  service_cause  0, sis=X-cisco-sis-, majNum=1, minNum=0, addiNum=0

11:37:18:542 g [sipCC] sip_callclient_setIsReg2Srst() bSrst=1 , bCme 0

11:37:18:544 g [sipCC] sip_callclient_addLine() add line, id=1 reg_state 1  dn 336

11:37:18:545 % [cent] FSM event(REGISTER_OK) / state(REGISTERING) / cause(0)

11:37:18:546 % [cent] State REGISTERING --> REGISTERED

11:37:18:547 g [sipCC] sip_callclient_registeredNotify()

11:37:18:553 w [NTP] Created NTP task successful

11:37:18:554 w [NTP] ----- szNTPSVR1=192.168.64.2, szNTPSVR2=0.0.0.0,

11:37:18:555 w [NTP] msntp_run()     1189  nSvrCount = 1

11:37:18:555 w [NTP] find_address()  58 hostname=192.168.64.2

11:37:18:558 w [NTP] run_client()     943

11:37:18:561 w [NTP] read_packet()    625    packet length=48

11:37:18:563 w [NTP] read_packet()    640  bNeedCheckLI=0,  data->mode=4, failed=0, data->status=0, data->version=3, data->stratum=2

11:37:18:564 w [NTP] read_packet()    663    failed=0

11:37:18:565 w [NTP] read_packet()    706    dispersion=0.000000

11:37:18:566 w [NTP] run_client()     996  error=0.002691, minerr=0.000000

11:37:18:567 w [PROVISION] setDateTime() get CFG value fail, set GMT time to system

11:37:18:607 x [SIP-Stack] SIP : 1/0 : dm_ev_shr_req_pend_subsc_resp_hdlr : 40004: Subscription response error: status=404n
2017/05/23 11:37:19:561 1 The required EnergyWise Domain or Secret not configured


[Vlad1983]

проблема известна

[sp1er]

Проблема может и известна, а вот решение есть ли какое либо?

[fecyt]

По идее, нажатие # должно игнорировать таймер. А вот автодиал чтобы происходил, хз. Если все правила убрать и оставить только <TEMPLATE MATCH="*" Timeout="1" /> - это сработает?

[vlego]

Проблема может и известна, а вот решение есть ли какое либо?

У Вас этот телефон 6901 по UDP подключен ? если да - попробуйте SIP only on TCP и перегрузите аппарат.
**
The problem was in freepbx, i have to enable voice over tcp, default is on UDP and cisco knows SIP only on TCP. After this changes the phone register without problemes.

Can be closed.
https://supportforums.cisco.com/discuss ... p-6901-sip

[Vlad1983]

производителю плевать на эту линейку с 2012
если действительно ошибка с игнором диалплана есть, то помощи уже не ждите
можно попробовать откатиться на предыдущие версии

попробовать запятую после цифры + Tone="Hold"

Код: выделить все

<TEMPLATE MATCH="1,.." Timeout="0" Tone="Hold" />

должны услышать сразу после 1 тон Hold