Подскажите, имеется голосовой шлюз TAU-72 (SIP) сервер Asterisk.
Сервер и шлюз находятся в одной стойке в одной лок. сети, в одной подсети. т.е. взаимодействуют локально.
Используем вместо UDP протокол TCP (исторически сложилось)
Порты TAU зарегистрированы на Asterisk. Длительность регистрации составляет 2 мин.
Возникает ситуация:
1. При первой регистрации - регистрация проходит успешно
TAU Asterisk
| -------REGISTER ------------> |
|<--- 401 Unathorization ------ |
| -----REGISTER (+digest) ---> |
| <--------200 ОК ----------------|
Проходит чуть меньше 2 мин со стороны TAU для продления регистрации приходит запрос REGISTER, сервер Asterisk отвечает 401, это видно по консоли самого сервера и по tcpdump на сервере (работаем по TCP) соот. от TAU приходит ACK. Но в логах TAU нет информации что он принял 401 и соот. TAU не повторяет запрос REGISTER с нужным digest в результате на станции регистрация удаляется из-за окончания срока действия контакта.
Меньше чем через 2 мин TAU отправляет запрос на REGISTER и всё успешно регистрируется и там весь день.
В чём может быть причина ?
Версия TAU-72 build 2.14.0.284
Лог TAU, например номер 1014, успешная регистрация
Код: Выделить всё
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.495)[sip]tport_release(0x40258630): 0x4033a198 by 0x40390c88 with 0x4034fc18
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.497)[sip]auth_digest_challenge_get(): got 8
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.500)[sip]tport_tsend(0x40258630) tpn = tcp/192.168.1.167:5060/sip
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.502)[sip]tport_vsend returned 809
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.503)[sip]send 809 bytes to tcp/[192.168.1.167]:5060 at 07:46:39.312984:
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.504)[sip] ------------------------------------------------------------------------
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.505)[sip] REGISTER sip:192.168.1.167 SIP/2.0
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.506)[sip] Via: SIP/2.0/TCP 192.168.1.9;branch=z9hG4bK9pprQ1UBDmSNK
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.507)[sip] Max-Forwards: 70
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.509)[sip] From: <sip:1014@192.168.1.167>;tag=BZH1Bm30QHc5D
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.510)[sip] To: <sip:1014@192.168.1.167>
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.511)[sip] Call-ID: 2e6caa4a-1179-1239-7096-a8f94b01aa7a
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.512)[sip] CSeq: 2173960 REGISTER
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.513)[sip] Contact: <sip:1014@192.168.1.9:5060>
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.514)[sip] Expires: 120
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.515)[sip] User-Agent: TAU-72 build 2.14.0.284 sofia-sip/1.12.10
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.516)[sip] Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.517)[sip] Supported: timer, 100rel, replaces, path
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.518)[sip] Authorization: Digest username="1014", realm="asterisk", nonce="1589555075/eb59da3adc6895de00f0401d61d64500", cnonce="YG9BzhF5EjmWcKj5SwGqeg", opaque="4cf9368b2c12b282", algorithm=MD5, uri="sip:19
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.520)[sip] Content-Length: 0
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.521)[sip]
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.522)[sip] ------------------------------------------------------------------------
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.523)[sip]tport(0x40258630): reset timer
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.524)[sip]nta: sent REGISTER (2173960) to tcp/192.168.1.167:5060/sip
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.525)[sip]tport_pend(0x40258630): pending 0x40391db8 for tcp/192.168.1.167:5060 (already 60)
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.526)[sip]nua: nua_application_event: entering
May 15 18:04:35 vgw03 user.debug vgw03.mdlv: 2.14.0.284|(35.527)[app:dbg]SIP: got nua_r_register : 100(Request Authorized by Cache)
May 15 18:04:35 vgw03 user.debug vgw03.mdlv: 2.14.0.284|(35.528)[app:dbg]sip: endpoint 11: REGISTER: 100 Request Authorized by Cache
May 15 18:04:35 vgw03 user.debug vgw03.mdlv: 2.14.0.284|(35.529)[app:dbg]sip: endpoint 11: REGISTER: 100 Request Authorized by Cache
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.531)[sip]nta: outgoing_free(0x40390c88)
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.532)[sip]tport(0x40258630): reset timer
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.533)[sip]tport_wakeup(0x40258630): events IN
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.534)[sip]tport_recv_event(0x40258630)
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.535)[sip]tport_recv_iovec(0x40258630) msg 0x4033a198 from (tcp/192.168.1.167:5060) has 455 bytes, veclen = 1
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.537)[sip]recv 455 bytes from tcp/[192.168.1.167]:5060 at 07:46:39.348026:
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.538)[sip] ------------------------------------------------------------------------
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.540)[sip] SIP/2.0 200 OK
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.541)[sip] Via: SIP/2.0/TCP 192.168.1.9;rport=42573;received=192.168.1.9;branch=z9hG4bK9pprQ1UBDmSNK
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.542)[sip] Call-ID: 2e6caa4a-1179-1239-7096-a8f94b01aa7a
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.543)[sip] From: <sip:1014@192.168.1.167>;tag=BZH1Bm30QHc5D
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.544)[sip] To: <sip:1014@192.168.1.167>;tag=z9hG4bK9pprQ1UBDmSNK
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.545)[sip] CSeq: 2173960 REGISTER
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.546)[sip] Date: Fri, 15 May 2020 15:04:35 GMT
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.547)[sip] Contact: <sip:1014@192.168.1.9:42573;transport=TCP>;expires=119
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.548)[sip] Expires: 120
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.550)[sip] Server: FPBX-14.0.13.23(13.27.1)
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.551)[sip] Content-Length: 0
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.552)[sip]
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.553)[sip] ------------------------------------------------------------------------
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.554)[sip]tport_deliver(0x40258630): msg 0x4033a198 (455 bytes) from tcp/192.168.1.167:5060/sip next=(nil)
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.555)[sip]nta: received 200 OK for REGISTER (2173960)
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.556)[sip]nta: 200 OK is going to a transaction
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.557)[sip]nta_outgoing: RTT is 57.256 ms
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.558)[sip]tport_release(0x40258630): 0x40391db8 by 0x4036ff30 with 0x4033a198
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.560)[sip]nua(): refresh register after 81 seconds (in [60..90])
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.561)[sip]nua(): refresh register after 81 seconds
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.563)[sip]nta: selecting scheme sip
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.564)[sip]tport_tsend(0x49b288) tpn = */192.168.1.167:5060
May 15 18:04:35 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(35.566)[sip]tport_resolve addrinfo = 192.168.1.167:5060Лог запроса когда TAU не отвечает на 401, по факту в логов ответа 401 нет, хотя в TCPDUMP со стороны TAU есть пакет ACK подтверждающий получениея
Код: Выделить всё
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.500)[sip]tport_tsend(0x40258630) tpn = tcp/192.168.1.167:5060/sip
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.502)[sip]tport_vsend returned 809
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.503)[sip]send 809 bytes to tcp/[192.168.1.167]:5060 at 07:48:00.313352:
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.504)[sip] ------------------------------------------------------------------------
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.504)[sip] REGISTER sip:192.168.1.167 SIP/2.0
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.505)[sip] Via: SIP/2.0/TCP 192.168.1.9;branch=z9hG4bKScr3FUgrgmaga
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.506)[sip] Max-Forwards: 70
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.507)[sip] From: <sip:1014@192.168.1.167>;tag=BZH1Bm30QHc5D
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.507)[sip] To: <sip:1014@192.168.1.167>
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.508)[sip] Call-ID: 2e6caa4a-1179-1239-7096-a8f94b01aa7a
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.511)[sip] CSeq: 2173961 REGISTER
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.511)[sip] Contact: <sip:1014@192.168.1.9:5060>
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.512)[sip] Expires: 120
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.513)[sip] User-Agent: TAU-72 build 2.14.0.284 sofia-sip/1.12.10
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.513)[sip] Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, INFO
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.514)[sip] Supported: timer, 100rel, replaces, path
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.515)[sip] Authorization: Digest username="1014", realm="asterisk", nonce="1589555075/eb59da3adc6895de00f0401d61d64500", cnonce="YG9BzhF5EjmWcKj5SwGqeg", opaque="4cf9368b2c12b282", algorithm=MD5, uri="sip:19
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.516)[sip] Content-Length: 0
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.516)[sip]
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.517)[sip] ------------------------------------------------------------------------
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.518)[sip]tport(0x40258630): reset timer
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.520)[sip]nta: sent REGISTER (2173961) to tcp/192.168.1.167:5060/sip
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.521)[sip]tport_pend(0x40258630): pending 0x403028a0 for tcp/192.168.1.167:5060 (already 67)
May 15 18:05:56 vgw03 user.debug vgw03.mdlv: 2.14.0.284|(56.619)[app:dbg]===== registration timer ====reg_timer_task=============================
May 15 18:05:56 vgw03 user.debug vgw03.mdlv: 2.14.0.284|(56.619)[app:dbg]sip: endpoint 37: REGISTER pair 0
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.620)[sip]nua: nua_register: entering
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.621)[sip]nua(0x4032a468): sent signal r_register
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.623)[sip]nua: nua_stack_set_params: entering
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.624)[sip]soa_set_params(static::0x40317aa0, ...) called
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.625)[sip]nta_leg_tcreate(0x40393080)
May 15 18:05:56 vgw03 user.notice vgw03.mdlv: 2.14.0.284|(56.626)[sip]nua(0x4032a468): adding register usage