Jump to content
Vodia PBX forum
chrispopp

Snom 735 and Snom 785 do not provision correctly

Recommended Posts

Testing with the new Snom phones from Snom.

 

The Snom D735 does provision but only registers on TCP/UDP. Not on TLS. It says Network failure.

The Snom D785 says: A secure connection has been rejected which offered an unknown certificate. You can explicitly give permission to the trust this connection via the web interface.

 

Am I doing anything wrong? Seems they all have issues with the built in certificates.

Share this post


Link to post
Share on other sites

What version of the PBX are you on? We have a 62.0.3 out right now on which Snom 735 and 785 both should be provisioning on TLS just fine.

Share this post


Link to post
Share on other sites

funny i am struggling with a similar issue with 765, 760, 720, 725

phone registeres on tls but then looses regisgtration.

i am running 61.0.2 (CentOS64)

Share this post


Link to post
Share on other sites

The new snom phones validate the certificates by default - and the new 62 templates should provision the Root CA into the phones. But you can also get automatically certificates from the letsencrypt root CA.

Share this post


Link to post
Share on other sites

i don't see an issue with certificates. here is a log file of a phone.

 

Feb 7 10:21:10.004 [INFO ] PHN: WEB: Request 7779/387/0: GET /normal.css HTTP/1.1
Feb 7 10:21:10.005 [INFO ] PHN: WEB: 7779 Basic authentication.
Feb 7 10:21:10.009 [INFO ] PHN: WEB: Request 7783/384/0: GET /fox.css HTTP/1.1
Feb 7 10:21:10.010 [INFO ] PHN: WEB: 7783 Basic authentication.
Feb 7 10:21:14.528 [INFO ] PHN: WEB: Request 7783/481/0: GET /log.htm HTTP/1.1
Feb 7 10:21:14.529 [INFO ] PHN: WEB: 7783 Basic authentication.
Feb 7 10:21:14.628 [INFO ] PHN: WEB: Request 7783/387/0: GET /normal.css HTTP/1.1
Feb 7 10:21:14.628 [INFO ] PHN: WEB: 7783 Basic authentication.
Feb 7 10:21:14.635 [INFO ] PHN: WEB: Request 7779/384/0: GET /fox.css HTTP/1.1
Feb 7 10:21:14.635 [INFO ] PHN: WEB: 7779 Basic authentication.
Feb 7 10:21:15.125 [NOTICE] PHN: TPL: Socket 7782 idle/connect timeout
Feb 7 10:21:24.633 [NOTICE] PHN: TPL: Socket 7783 idle/connect timeout
Feb 7 10:21:24.638 [NOTICE] PHN: TPL: Socket 7779 idle/connect timeout
Feb 7 10:21:25.212 [INFO ] PHN: presence::erase konce 6077717784@domain.com
Feb 7 10:21:25.212 [INFO ] PHN: presence::erase konce 6097211329@domain.com
Feb 7 10:21:25.213 [INFO ] PHN: presence::erase konce 9549985190@domain.com
Feb 7 10:21:28.450 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:21:35.086 [INFO ] PHN: WEB: Request 7786/481/0: GET /log.htm HTTP/1.1
Feb 7 10:21:35.086 [INFO ] PHN: WEB: 7786 Basic authentication.
Feb 7 10:21:35.200 [INFO ] PHN: WEB: Request 7786/387/0: GET /normal.css HTTP/1.1
Feb 7 10:21:35.203 [INFO ] PHN: WEB: 7786 Basic authentication.
Feb 7 10:21:35.210 [INFO ] PHN: WEB: Request 7786/384/0: GET /fox.css HTTP/1.1
Feb 7 10:21:35.212 [INFO ] PHN: WEB: 7786 Basic authentication.
Feb 7 10:21:37.807 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:21:42.685 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:21:45.216 [NOTICE] PHN: TPL: Socket 7786 idle/connect timeout
Feb 7 10:21:59.083 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:22:07.809 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:22:08.932 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135313
Feb 7 10:22:08.932 [DEBUG0] SIP: send REGISTER (57852: 313534383638383236353431333633-oxgj5r7hs510) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:22:08.956 [DEBUG0] SIP: sip::process_registrar_packet: Received 200 Ok
Feb 7 10:22:08.957 [INFO ] SIP: Registered at registrar as 10@domain.com (Expires: 179 secs)
Feb 7 10:22:22.583 [DEBUG0] SIP: refresh subscription 12 in 1827 sec
Feb 7 10:22:22.592 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135315
Feb 7 10:22:22.592 [DEBUG0] SIP: send SUBSCRIBE (4: 313534393535323834303237363831-p10ij3kd99nq) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:22:29.595 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:22:37.812 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:22:42.695 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:22:50.553 [DEBUG0] SIP: refresh subscription 13 in 1813 sec
Feb 7 10:22:50.562 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135316
Feb 7 10:22:50.562 [DEBUG0] SIP: send SUBSCRIBE (3: 313534393535323834303237303638-gjhqa6xtyj2u) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:23:00.107 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:23:07.815 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:23:30.629 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:23:37.817 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:23:38.467 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135317
Feb 7 10:23:38.467 [DEBUG0] SIP: send REGISTER (57853: 313534383638383236353431333633-oxgj5r7hs510) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:23:38.492 [DEBUG0] SIP: sip::process_registrar_packet: Received 200 Ok
Feb 7 10:23:38.494 [INFO ] SIP: Registered at registrar as 10@domain.com (Expires: 179 secs)
Feb 7 10:23:42.706 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:23:48.535 [INFO ] PHN: LLDP: Skipped packet (64 bytes), not from router/bridge
Feb 7 10:24:01.272 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:24:07.613 [DEBUG0] SIP: refresh subscription 12 in 2660 sec
Feb 7 10:24:07.619 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135319
Feb 7 10:24:07.621 [DEBUG0] SIP: send SUBSCRIBE (5: 313534393535323834303237363831-p10ij3kd99nq) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:24:07.821 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:24:31.765 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:24:37.823 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:24:42.717 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:25:02.307 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:25:05.583 [DEBUG0] SIP: refresh subscription 13 in 2265 sec
Feb 7 10:25:05.592 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135320
Feb 7 10:25:05.592 [DEBUG0] SIP: send SUBSCRIBE (4: 313534393535323834303237303638-gjhqa6xtyj2u) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:25:07.825 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:25:08.003 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135321
Feb 7 10:25:08.003 [DEBUG0] SIP: send REGISTER (57854: 313534383638383236353431333633-oxgj5r7hs510) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:25:08.027 [DEBUG0] SIP: sip::process_registrar_packet: Received 200 Ok
Feb 7 10:25:08.028 [INFO ] SIP: Registered at registrar as 10@domain.com (Expires: 180 secs)
Feb 7 10:25:10.193 [INFO ] PHN: WEB: Request 7787/72/0: GET / HTTP/1.1
Feb 7 10:25:10.193 [INFO ] PHN: WEB: 7787 Basic authentication.
Feb 7 10:25:10.194 [INFO ] PHN: Authentication triggered. Set flag back.
Feb 7 10:25:26.989 [INFO ] PHN: WEB: Request 7788/72/0: GET / HTTP/1.1
Feb 7 10:25:26.991 [INFO ] PHN: WEB: 7788 Basic authentication.
Feb 7 10:25:26.992 [INFO ] PHN: Authentication triggered. Set flag back.
Feb 7 10:25:32.822 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:25:37.828 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:25:42.728 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:26:03.414 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:26:07.832 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:26:19.643 [DEBUG0] SIP: refresh subscription 12 in 2588 sec
Feb 7 10:26:19.651 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135323
Feb 7 10:26:19.651 [DEBUG0] SIP: send SUBSCRIBE (6: 313534393535323834303237363831-p10ij3kd99nq) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:26:25.213 [INFO ] PHN: presence::erase konce 18@domain.com
Feb 7 10:26:25.213 [INFO ] PHN: presence::erase konce 2014377440@domain.com
Feb 7 10:26:25.213 [INFO ] PHN: presence::erase konce 2126435712@domain.com
Feb 7 10:26:25.213 [INFO ] PHN: presence::erase konce 2243331176@domain.com
Feb 7 10:26:25.213 [INFO ] PHN: presence::erase konce 7182464100@domain.com
Feb 7 10:26:25.213 [INFO ] PHN: presence::erase konce 7182549048@domain.com
Feb 7 10:26:25.213 [INFO ] PHN: presence::erase konce 7183959944@domain.com
Feb 7 10:26:25.214 [INFO ] PHN: presence::erase konce 7188526503@domain.com
Feb 7 10:26:25.214 [INFO ] PHN: presence::erase konce 810@domain.com
Feb 7 10:26:25.214 [INFO ] PHN: presence::erase konce 9173868245@domain.com
Feb 7 10:26:25.214 [INFO ] PHN: presence::erase konce Anonymous@domain.com
Feb 7 10:26:33.985 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:26:37.833 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:26:38.037 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135324
Feb 7 10:26:38.037 [DEBUG0] SIP: send REGISTER (57855: 313534383638383236353431333633-oxgj5r7hs510) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:26:38.063 [DEBUG0] SIP: sip::process_registrar_packet: Received 200 Ok
Feb 7 10:26:38.064 [INFO ] SIP: Registered at registrar as 10@domain.com (Expires: 179 secs)
Feb 7 10:26:42.741 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:26:44.612 [DEBUG0] SIP: refresh subscription 13 in 2276 sec
Feb 7 10:26:44.618 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135326
Feb 7 10:26:44.618 [DEBUG0] SIP: send SUBSCRIBE (5: 313534393535323834303237303638-gjhqa6xtyj2u) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:27:04.527 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:27:07.836 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:27:35.051 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:27:37.838 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:27:42.752 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:28:05.642 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:28:07.573 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135327
Feb 7 10:28:07.573 [DEBUG0] SIP: send REGISTER (57856: 313534383638383236353431333633-oxgj5r7hs510) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:28:07.597 [DEBUG0] SIP: sip::process_registrar_packet: Received 200 Ok
Feb 7 10:28:07.598 [INFO ] SIP: Registered at registrar as 10@domain.com (Expires: 178 secs)
Feb 7 10:28:07.842 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:28:27.642 [DEBUG0] SIP: refresh subscription 13 in 2134 sec
Feb 7 10:28:27.652 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135329
Feb 7 10:28:27.653 [DEBUG0] SIP: send SUBSCRIBE (6: 313534393535323834303237303638-gjhqa6xtyj2u) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:28:29.672 [DEBUG0] SIP: refresh subscription 12 in 2136 sec
Feb 7 10:28:29.678 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135330
Feb 7 10:28:29.678 [DEBUG0] SIP: send SUBSCRIBE (7: 313534393535323834303237363831-p10ij3kd99nq) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:28:36.275 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:28:37.847 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:28:42.762 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:29:06.787 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:29:07.850 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:29:36.607 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135331
Feb 7 10:29:36.607 [DEBUG0] SIP: send REGISTER (57857: 313534383638383236353431333633-oxgj5r7hs510) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:29:36.633 [DEBUG0] SIP: sip::process_registrar_packet: Received 200 Ok
Feb 7 10:29:36.634 [INFO ] SIP: Registered at registrar as 10@domain.com (Expires: 182 secs)
Feb 7 10:29:37.311 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:29:37.852 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:29:42.607 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:42.772 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:42.775 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:29:44.342 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:44.345 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:44.351 [INFO ] GUI: find_function_key_for_uri: Looking to match 10@domain.com
Feb 7 10:29:44.352 [INFO ] GUI: GUI: Allocating channel 18, line 1
Feb 7 10:29:44.365 [NOTICE] CSTA: csta_cid = 18 phone_cid18
Feb 7 10:29:44.368 [DEBUG0] MEDIA: MediaIpc::rtpSetup: rtp: RP114 rtcp: RC114 start: 49152 end: 65534
Feb 7 10:29:44.373 [INFO ] SIP: Dialog 18/114/1 going to trying
Feb 7 10:29:44.373 [INFO ] GUI: GUI: Line-Seize subscription was not sent
Feb 7 10:29:44.373 [DEBUG0] MEDIA: MediaIpc::setSpeakerDefault: 6 15
Feb 7 10:29:44.413 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:44.427 [DEBUG0] PHN: Request lookup for number sip:810@domain.com
Feb 7 10:29:44.547 [DEBUG0] MEDIA: Socket 0x4e85f0/noname: state connected(5)
Feb 7 10:29:44.547 [DEBUG0] MEDIA: Socket 0x4e8cd8/noname: state connected(5)
Feb 7 10:29:44.565 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135333
Feb 7 10:29:44.565 [DEBUG0] SIP: send INVITE (1: 313534393535333338343233333330-6t96vn1raij8) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:29:44.572 [INFO ] SIP: Dialog 18/114/0 going to trying
Feb 7 10:29:44.590 [INFO ] SIP: Dialog 18/114/1 going to early
Feb 7 10:29:44.605 [INFO ] SIP: Dialog 18/114/3 going to confirmed
Feb 7 10:29:44.613 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135334
Feb 7 10:29:44.614 [DEBUG0] SIP: send ACK (1: 313534393535333338343233333330-6t96vn1raij8) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:29:44.621 [DEBUG0] MEDIA: RingOrEarlyMedia Command: ssrc: cb0a16b4 to: cmd:
Feb 7 10:29:44.625 [DEBUG0] SIP: SRTP enabled
Feb 7 10:29:44.625 [NOTICE] SIP: RTP: set_destination RP114 adr=xxx.xxx.xxx.xxx:55952
Feb 7 10:29:44.625 [INFO ] SIP: RTP: set_audible(0/0 -> 1/1): RP114 changed=1, update_req=1, adr=xxx.xxx.xxx.xxx:55952
Feb 7 10:29:44.625 [DEBUG0] MEDIA: MediaIpc::SetJitterBuffer
Feb 7 10:29:44.627 [DEBUG0] MEDIA: MediaIpc::setStream: prot Udp ssrc cb0a16b4 rtp RP114 rtcp RC114 stream 0 r 1 w 1 dtmf inb 0 outb 1 outbpt 101 codec 0 length 160 ocs 0 ssrtp 0 enc: 0
Feb 7 10:29:44.627 [DEBUG0] MEDIA: MediaIpc::setStream: rtp addr: Udp:xxx.xxx.xxx.xxx:55952 :rtcp addr: Udp:[::]:0 srtp: 1 ssrtp: 0 rfc3551: 1 tos: 184 keepalive: 1
Feb 7 10:29:44.627 [DEBUG0] MEDIA: rtpmap_packet: '000015010808150103031501121228010909150165651501'
Feb 7 10:29:44.676 [DEBUG0] MEDIA: MediaIpc::rtpSymmetric: RP114 0
Feb 7 10:29:44.677 [INFO ] SIP: sip::gui_connected(18, 3, 1, 0)
Feb 7 10:29:44.690 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:44.691 [DEBUG0] MEDIA: MediaIpc::setSpeakerDestination: 6
Feb 7 10:29:44.691 [DEBUG0] MEDIA: MediaIpc::setVolume: 15
Feb 7 10:29:44.691 [DEBUG0] MEDIA: MediaIpc::setMicroVolume: 5 0
Feb 7 10:29:44.692 [INFO ] GUI: speaker_mixer: 1
Feb 7 10:29:44.692 [DEBUG0] MEDIA: MediaIpc::setSpeakerMixer: 1
Feb 7 10:29:44.692 [DEBUG0] MEDIA: Synthesizer Command: PLAY 0 0 0
Feb 7 10:29:44.771 [DEBUG0] PHN: Request lookup for number sip:810@domain.com;user=phone
Feb 7 10:29:45.047 [DEBUG0] PHN: Request lookup for number sip:810@domain.com
Feb 7 10:29:45.084 [DEBUG0] MEDIA: UdpStream: 0 (1, 1) RP114 '303030303135303130383038313530313033303331353031313231323238303130393039313530313635363531353031' - 0 0
Feb 7 10:29:45.084 [DEBUG0] MEDIA: add ssrc 3406436020 for rtp socket RP114
Feb 7 10:29:45.084 [DEBUG0] MEDIA: Start/Change Call: 3406436020-----
Feb 7 10:29:45.085 [DEBUG0] MEDIA: Start Streaming at 0/0
Feb 7 10:29:45.085 [INFO ] MEDIA: 865176107 PlayCall: ssrc: 3406436020 codec: 0 codec_specific: 21 framelen: 160 read: 1 write: 1
Feb 7 10:29:45.085 [INFO ] MEDIA: 865176107 PlayCall: g726 convert: 0 outband_codec: 101 dtmf_type :2 silence: 0
Feb 7 10:29:45.085 [INFO ] MEDIA: 865176107 SetPlayState: 0 -> 1 active: 1
Feb 7 10:29:45.086 [INFO ] MEDIA: setAudioMode: set handsfree to profile 16
Feb 7 10:29:45.086 [INFO ] MEDIA: 865176109 CAudioTi::setAudioMode: set_ipp_mode 0->6!
Feb 7 10:29:45.086 [INFO ] MEDIA: 865176111 CAudioTi::SetInternAudioMode set_ipp_mode 0: 0->6 (0)!
Feb 7 10:29:45.086 [INFO ] MEDIA: 865176113 check_ipp_mode: 3/3
Feb 7 10:29:45.086 [INFO ] MEDIA: 865176114 StopCall - ssrc: 654321
Feb 7 10:29:45.087 [INFO ] MEDIA: 865176114 StopCall 0 - ssrc: 654321 active: 1 conf -1, all 1
Feb 7 10:29:45.087 [INFO ] MEDIA: 865176114 CAudioTi::StopCall: channel 0 active: 1 ssrc: 654321
Feb 7 10:29:45.087 [INFO ] MEDIA: 865176114 CAudioTi::StopCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:45.087 [INFO ] MEDIA: 865176114 CAudioTi::StopCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:45.087 [INFO ] MEDIA: 865176114 CAudioTi::StopCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:45.088 [INFO ] MEDIA: 865176114 coding_state: 6
Feb 7 10:29:45.088 [INFO ] MEDIA: 865176114 ipp_mode: 3
Feb 7 10:29:45.088 [INFO ] MEDIA: 865176115 coding_state: 6
Feb 7 10:29:45.091 [INFO ] MEDIA: 865176115 ipp_mode: 3
Feb 7 10:29:45.091 [INFO ] MEDIA: 865176117 check_coding_state: 5/4
Feb 7 10:29:45.091 [INFO ] MEDIA: 865176117 StopCall: active_channels_: 0 ssrc: 654321 update_: 0
Feb 7 10:29:45.091 [INFO ] MEDIA: 865176118 CAudioTi::StopCall: channel 0 active: 0 ssrc: 0
Feb 7 10:29:45.092 [INFO ] MEDIA: 865176118 CAudioTi::StopCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:45.092 [INFO ] MEDIA: 865176118 CAudioTi::StopCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:45.092 [INFO ] MEDIA: 865176118 CAudioTi::StopCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:45.092 [INFO ] MEDIA: 865176118 SetConferenceLevelChannel(0, 1 0)
Feb 7 10:29:45.092 [INFO ] MEDIA: 865176118 Current gain row: 2, new row: 0!
Feb 7 10:29:45.093 [INFO ] MEDIA: PlayCall new params: ssrc: 3406436020 seq: 0 codec: 0 codec spec: 21 len: 160 outbpt: 101 dtmf type: 2 sil: 0 g729: 0
Feb 7 10:29:45.093 [INFO ] MEDIA: CAudioTi::PlayCall: use free channel 0
Feb 7 10:29:45.093 [INFO ] MEDIA: 865176135 CAudioTi::PlayCall: active channels: 0
Feb 7 10:29:45.093 [INFO ] MEDIA: 865176137 CAudioTi::PlayCall: channel 0 active: 0 ssrc: 0
Feb 7 10:29:45.093 [INFO ] MEDIA: 865176138 CAudioTi::PlayCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:45.094 [INFO ] MEDIA: 865176138 CAudioTi::PlayCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:45.094 [INFO ] MEDIA: 865176139 CAudioTi::PlayCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:45.094 [INFO ] MEDIA: 865176139 CAudioTi::PlayCall(3406436020), codec 0, outband_payload_type 101 dtmf type 2
Feb 7 10:29:45.094 [INFO ] MEDIA: 865176139 CAudioTi::PlayCall: new channel - active channels: 1
Feb 7 10:29:45.095 [INFO ] MEDIA: 865176142 CAudioTi::PlayCall: channel id: 0 active: 0 ssrc: 3406436020
Feb 7 10:29:45.095 [INFO ] MEDIA: 865176142 coding_state: 4
Feb 7 10:29:45.095 [INFO ] MEDIA: 865176142 ipp_mode: 3
Feb 7 10:29:45.095 [INFO ] MEDIA: CAudioTi::PlayCall: jb_mode 1 jb_min 0 jb_max 300 jb_avg 60
Feb 7 10:29:45.098 [INFO ] MEDIA: 865176143 PlayCall: pbPT 101 dtmf_type: 2
Feb 7 10:29:45.102 [INFO ] MEDIA: coding profile: 1 ptype: 0 ssrc: 3406436020 vad: 0 rate_idx: 0 dtmf_relay: 4 dtmf_pt: 101 vif: 1280/1280 0 65535
Feb 7 10:29:45.102 [INFO ] MEDIA: sec decoder: 0 0 0
Feb 7 10:29:45.102 [INFO ] MEDIA: 865176143 request_coding_params 0!
Feb 7 10:29:45.103 [INFO ] MEDIA: 865176170 request_coding_profile_done!
Feb 7 10:29:45.103 [INFO ] MEDIA: 865176171 request_coding state 1
Feb 7 10:29:45.103 [INFO ] MEDIA: 865176172 check_coding_state: 6/6
Feb 7 10:29:45.103 [INFO ] MEDIA: 865176173 CAudioTi::SetInternAudioMode set_ipp_mode 0: 6->6 (0)!
Feb 7 10:29:45.103 [INFO ] MEDIA: 865176175 check_ipp_mode: 3/3
Feb 7 10:29:45.103 [INFO ] MEDIA: 865176186 SetConferenceLevelChannel(0, 1 0)
Feb 7 10:29:45.104 [INFO ] MEDIA: 865176186 Current gain row: 0, new row: 0!
Feb 7 10:29:45.104 [INFO ] MEDIA: 865176186 CAudioTi::PlayCall: active channels: 1
Feb 7 10:29:45.104 [INFO ] MEDIA: 865176186 CAudioTi::PlayCall: channel 0 active: 1 ssrc: 3406436020
Feb 7 10:29:45.105 [INFO ] MEDIA: 865176187 CAudioTi::PlayCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:45.105 [INFO ] MEDIA: 865176187 CAudioTi::PlayCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:45.105 [INFO ] MEDIA: 865176187 CAudioTi::PlayCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:45.105 [INFO ] MEDIA: setAudioMode: set handsfree to profile 16
Feb 7 10:29:45.105 [INFO ] MEDIA: 865176189 CAudioTi::setAudioMode: set_ipp_mode 6->6!
Feb 7 10:29:45.105 [INFO ] MEDIA: 865176198 datacallback: start sending: 3406436020 playstate: 1
Feb 7 10:29:45.106 [INFO ] MEDIA: 865176199 CAudioTi::SetInternAudioMode set_ipp_mode 0: 6->6 (0)!
Feb 7 10:29:45.106 [INFO ] MEDIA: 865176199 CAudioTi::SetInternAudioMode no change
Feb 7 10:29:45.106 [INFO ] MEDIA: 865176201 SetConferenceLevelChannel(0, 1 8)
Feb 7 10:29:45.107 [INFO ] MEDIA: 865176201 Current gain row: 0, new row: 8!
Feb 7 10:29:45.107 [INFO ] MEDIA: SetMicVolume: 0 -> 5 high: 0 / 0
Feb 7 10:29:45.107 [INFO ] MEDIA: 865176203 mute 0 0
Feb 7 10:29:45.107 [INFO ] MEDIA: 865176223 mute_state: 0
Feb 7 10:29:45.107 [INFO ] MEDIA: 865176224 SetPlayState: 1 -> 1 active: 1
Feb 7 10:29:45.107 [INFO ] MEDIA: 865176224 Updating synth programm
Feb 7 10:29:45.108 [DEBUG0] MEDIA: 865176224 BuildEventPacket: Reset event
Feb 7 10:29:45.108 [DEBUG0] MEDIA: found stream without packet ssrc
Feb 7 10:29:45.108 [DEBUG0] MEDIA: set stream packet ssrc 1988925535
Feb 7 10:29:45.111 [INFO ] MEDIA: HandleChangedPacketSsrc: set first ssrc 1988925535
Feb 7 10:29:45.112 [DEBUG0] PHN: LoopMon: LCS/48851015 took 354 (0) msecs, started Feb 7 10:29:44, 13 tasks
Feb 7 10:29:49.364 [DEBUG0] MEDIA: MediaIpc::setSpeakerDestination: 6
Feb 7 10:29:49.368 [DEBUG0] MEDIA: MediaIpc::setVolume: 15
Feb 7 10:29:49.372 [DEBUG0] MEDIA: MediaIpc::setMicroVolume: 5 0
Feb 7 10:29:49.373 [INFO ] GUI: speaker_mixer: 3
Feb 7 10:29:49.373 [DEBUG0] MEDIA: MediaIpc::setSpeakerMixer: 3
Feb 7 10:29:49.374 [DEBUG0] MEDIA: Synthesizer Command: PLAY 0 0 0
Feb 7 10:29:49.384 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:49.424 [INFO ] MEDIA: setAudioMode: set handsfree to profile 16
Feb 7 10:29:49.424 [INFO ] MEDIA: 865180837 CAudioTi::setAudioMode: set_ipp_mode 6->6!
Feb 7 10:29:49.425 [INFO ] MEDIA: 865180837 CAudioTi::SetInternAudioMode set_ipp_mode 0: 6->6 (0)!
Feb 7 10:29:49.425 [INFO ] MEDIA: 865180837 CAudioTi::SetInternAudioMode no change
Feb 7 10:29:49.425 [INFO ] MEDIA: 865180841 SetConferenceLevelChannel(0, 1 8)
Feb 7 10:29:49.425 [INFO ] MEDIA: 865180842 Current gain row: 8, new row: 8!
Feb 7 10:29:49.425 [INFO ] MEDIA: SetMicVolume: 5 -> 5 high: 0 / 0
Feb 7 10:29:49.426 [INFO ] MEDIA: 865180844 SetPlayState: 1 -> 3 active: 1
Feb 7 10:29:49.426 [INFO ] MEDIA: 865180846 Updating synth programm
Feb 7 10:29:49.427 [DEBUG0] MEDIA: 865180848 SendDtmfToChannel 0
Feb 7 10:29:49.428 [DEBUG0] MEDIA: 865180849 SendDtmfToChannels: dtmf outband event init
Feb 7 10:29:49.428 [INFO ] MEDIA: 865180849 SendDtmfToSpeaker vol: 8
Feb 7 10:29:49.431 [DEBUG0] MEDIA: 865180853 BuildEventPacket: chn 0, ts 37200, act 1, count 3
Feb 7 10:29:49.431 [DEBUG0] MEDIA: 865180872 BuildEventPacket: chn 0, ts 37200, act 1, count 3
Feb 7 10:29:49.433 [DEBUG0] MEDIA: 865180892 BuildEventPacket: chn 0, ts 37200, act 1, count 3
Feb 7 10:29:49.443 [DEBUG0] MEDIA: 865180912 BuildEventPacket: chn 0, ts 37200, act 1, count 3
Feb 7 10:29:49.472 [DEBUG0] MEDIA: 865180932 BuildEventPacket: chn 0, ts 37200, act 1, count 3
Feb 7 10:29:49.503 [DEBUG0] MEDIA: 865180952 BuildEventPacket: chn 0, ts 37200, act 0, count 3
Feb 7 10:29:49.503 [DEBUG0] MEDIA: 865180972 BuildEventPacket: chn 0, ts 37200, act 0, count 2
Feb 7 10:29:49.522 [DEBUG0] MEDIA: 865180992 BuildEventPacket: chn 0, ts 37200, act 0, count 1
Feb 7 10:29:49.542 [DEBUG0] MEDIA: 865181012 BuildEventPacket: Reset event
Feb 7 10:29:49.555 [DEBUG0] MEDIA: MediaIpc::setSpeakerDestination: 6
Feb 7 10:29:49.562 [DEBUG0] MEDIA: MediaIpc::setVolume: 15
Feb 7 10:29:49.564 [DEBUG0] MEDIA: MediaIpc::setMicroVolume: 5 0
Feb 7 10:29:49.565 [INFO ] GUI: speaker_mixer: 1
Feb 7 10:29:49.565 [DEBUG0] MEDIA: MediaIpc::setSpeakerMixer: 1
Feb 7 10:29:49.566 [DEBUG0] MEDIA: Synthesizer Command: PLAY 0 0 0
Feb 7 10:29:49.572 [INFO ] MEDIA: setAudioMode: set handsfree to profile 16
Feb 7 10:29:49.572 [INFO ] MEDIA: 865181028 CAudioTi::setAudioMode: set_ipp_mode 6->6!
Feb 7 10:29:49.572 [INFO ] MEDIA: 865181028 CAudioTi::SetInternAudioMode set_ipp_mode 0: 6->6 (0)!
Feb 7 10:29:49.573 [INFO ] MEDIA: 865181028 CAudioTi::SetInternAudioMode no change
Feb 7 10:29:49.573 [INFO ] MEDIA: 865181034 SetConferenceLevelChannel(0, 1 8)
Feb 7 10:29:49.573 [INFO ] MEDIA: 865181034 Current gain row: 8, new row: 8!
Feb 7 10:29:49.573 [INFO ] MEDIA: SetMicVolume: 5 -> 5 high: 0 / 0
Feb 7 10:29:49.573 [INFO ] MEDIA: 865181037 SetPlayState: 3 -> 1 active: 1
Feb 7 10:29:49.728 [INFO ] MEDIA: 865181038 Updating synth programm
Feb 7 10:29:53.193 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:53.195 [DEBUG0] GUI: Line 18: EndCall (6)
Feb 7 10:29:53.202 [INFO ] SIP: RTP: set_audible(1/1 -> 0/0): RP114 changed=1, update_req=0, adr=xxx.xxx.xxx.xxx:55952
Feb 7 10:29:53.204 [DEBUG0] MEDIA: MediaIpc::rtpStats: cseq: 94412 ssrc: 3406436020 name: RP114 stream: 0 vqidx:
Feb 7 10:29:53.206 [DEBUG0] SIP: requesting call stats: 94412 in state confirmed
Feb 7 10:29:53.206 [INFO ] SIP: RTP: close stream 1, stats 1
Feb 7 10:29:53.206 [DEBUG0] MEDIA: MediaIpc::holdStream: prot: Udp ssrc: cb0a16b4 rtp: RP114 rtcp: RC114 stream: 0 holdstate: 0
Feb 7 10:29:53.213 [DEBUG0] MEDIA: MediaIpc::rtpSymmetric: RP114 0
Feb 7 10:29:53.225 [INFO ] SIP: Dialog 18/114/4 going to terminated
Feb 7 10:29:53.226 [INFO ] SIP: packet 1135333 stopped retransmission
Feb 7 10:29:53.232 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:53.235 [DEBUG0] MEDIA: Synthesizer Command: PLAY 0 0 0
Feb 7 10:29:53.236 [INFO ] GUI: synth_silent: connected lines: 0 of 0 state: Terminated inIdle: 0 inTerminated: 1
Feb 7 10:29:53.237 [INFO ] GUI: synth_silent: lines with call action: 0
Feb 7 10:29:53.237 [INFO ] GUI: synth_silent: set playstate idle and audio mode to none
Feb 7 10:29:53.237 [DEBUG0] MEDIA: MediaIpc::setSpeakerDestination: 0
Feb 7 10:29:53.242 [DEBUG0] MEDIA: MediaIpc::setMicroDestination: 0
Feb 7 10:29:53.243 [DEBUG0] MEDIA: MediaIpc::setVolume: 0
Feb 7 10:29:53.246 [DEBUG0] MEDIA: MediaIpc::setMicroVolume: 0 0
Feb 7 10:29:53.252 [INFO ] GUI: speaker_mixer: 0
Feb 7 10:29:53.252 [DEBUG0] MEDIA: MediaIpc::setSpeakerMixer: 0
Feb 7 10:29:53.255 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:53.256 [DEBUG0] MEDIA: MediaIpc::setSpeakerDefault: 6 15
Feb 7 10:29:53.325 [INFO ] PHN: WebImage::SetLocation http://%17:80
Feb 7 10:29:53.325 [INFO ] PHN: WebImage::SetLocation http://%17:80
Feb 7 10:29:53.405 [DEBUG0] SIP: Response CallStats 94412 (1) state terminated
Feb 7 10:29:53.406 [INFO ] SIP: RTP: set_audible(0/0 -> 0/0): RP114 changed=0, update_req=0, adr=xxx.xxx.xxx.xxx:55952
Feb 7 10:29:53.406 [DEBUG0] MEDIA: MediaIpc::rtpSymmetric: RP114 0
Feb 7 10:29:53.415 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135335
Feb 7 10:29:53.415 [DEBUG0] SIP: send BYE (2: 313534393535333338343233333330-6t96vn1raij8) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:29:53.422 [DEBUG0] MEDIA: UdpStream: 0 (0, 0) RP114 '' - 1 0
Feb 7 10:29:53.422 [DEBUG0] MEDIA: Stop Call: 3406436020-----
Feb 7 10:29:53.423 [DEBUG0] MEDIA: Stop Streaming at 425/67760
Feb 7 10:29:53.423 [INFO ] MEDIA: 865184683 pause call 3406436020 seqnr: 425
Feb 7 10:29:53.423 [INFO ] MEDIA: 865184706 Updating synth programm
Feb 7 10:29:53.424 [INFO ] MEDIA: 865184708 CAudioTi::setAudioMode: set_ipp_mode 6->0!
Feb 7 10:29:53.424 [INFO ] MEDIA: 865184708 CAudioTi::SetInternAudioMode set_ipp_mode 0: 6->0 (0)!
Feb 7 10:29:53.424 [INFO ] MEDIA: 865184713 check_ipp_mode: 0/0
Feb 7 10:29:53.425 [INFO ] MEDIA: 865184715 SetConferenceLevelChannel(0, 1 0)
Feb 7 10:29:53.425 [INFO ] MEDIA: 865184716 Current gain row: 0, new row: 0!
Feb 7 10:29:53.425 [INFO ] MEDIA: SetMicVolume: 5 -> 0 high: 0 / 0
Feb 7 10:29:53.425 [INFO ] MEDIA: 865184718 mute 0 1
Feb 7 10:29:53.425 [INFO ] MEDIA: 865184739 mute_state: 1
Feb 7 10:29:53.426 [INFO ] MEDIA: 865184742 SetPlayState: 1 -> 0 active: 1
Feb 7 10:29:53.426 [INFO ] MEDIA: 865184742 StopCall - ssrc: 3406436020
Feb 7 10:29:53.426 [INFO ] MEDIA: 865184742 StopCall 0 - ssrc: 3406436020 active: 1 conf -1, all 1
Feb 7 10:29:53.427 [INFO ] MEDIA: 865184742 CAudioTi::StopCall: channel 0 active: 1 ssrc: 3406436020
Feb 7 10:29:53.427 [INFO ] MEDIA: 865184742 CAudioTi::StopCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:53.427 [INFO ] MEDIA: 865184742 CAudioTi::StopCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:53.427 [INFO ] MEDIA: 865184743 CAudioTi::StopCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:53.427 [INFO ] MEDIA: 865184743 coding_state: 6
Feb 7 10:29:53.428 [INFO ] MEDIA: 865184743 ipp_mode: 0
Feb 7 10:29:53.428 [INFO ] MEDIA: 865184743 coding_state: 6
Feb 7 10:29:53.430 [INFO ] MEDIA: 865184743 ipp_mode: 0
Feb 7 10:29:53.430 [INFO ] MEDIA: 865184744 check_coding_state: 5/4
Feb 7 10:29:53.431 [INFO ] MEDIA: 865184744 StopCall: active_channels_: 0 ssrc: 3406436020 update_: 0
Feb 7 10:29:53.431 [INFO ] MEDIA: 865184745 CAudioTi::StopCall: channel 0 active: 0 ssrc: 0
Feb 7 10:29:53.431 [INFO ] MEDIA: 865184745 CAudioTi::StopCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:53.431 [INFO ] MEDIA: 865184747 CAudioTi::StopCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:53.432 [INFO ] MEDIA: 865184747 CAudioTi::StopCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:53.432 [INFO ] MEDIA: 865184747 SetConferenceLevelChannel(0, 1 0)
Feb 7 10:29:53.432 [INFO ] MEDIA: 865184747 Current gain row: 0, new row: 0!
Feb 7 10:29:53.432 [INFO ] MEDIA: 865184748 PlayCall: ssrc: 654321 codec: 0 codec_specific: 21 framelen: 160 read: 0 write: 1
Feb 7 10:29:53.432 [INFO ] MEDIA: 865184748 PlayCall: g726 convert: 0 outband_codec: 101 dtmf_type :2 silence: 0
Feb 7 10:29:53.433 [INFO ] MEDIA: PlayCall new params: ssrc: 654321 seq: 0 codec: 0 codec spec: 21 len: 160 outbpt: 101 dtmf type: 2 sil: 0 g729: 0
Feb 7 10:29:53.433 [INFO ] MEDIA: CAudioTi::PlayCall: use free channel 0
Feb 7 10:29:53.433 [INFO ] MEDIA: 865184748 CAudioTi::PlayCall: active channels: 0
Feb 7 10:29:53.433 [INFO ] MEDIA: 865184748 CAudioTi::PlayCall: channel 0 active: 0 ssrc: 0
Feb 7 10:29:53.434 [INFO ] MEDIA: 865184748 CAudioTi::PlayCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:53.434 [INFO ] MEDIA: 865184748 CAudioTi::PlayCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:53.434 [INFO ] MEDIA: 865184748 CAudioTi::PlayCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:53.434 [INFO ] MEDIA: 865184749 CAudioTi::PlayCall(654321), codec 0, outband_payload_type 101 dtmf type 2
Feb 7 10:29:53.435 [INFO ] MEDIA: 865184749 CAudioTi::PlayCall: new channel - active channels: 1
Feb 7 10:29:53.435 [INFO ] MEDIA: 865184749 CAudioTi::PlayCall: channel id: 0 active: 0 ssrc: 654321
Feb 7 10:29:53.435 [INFO ] MEDIA: 865184752 coding_state: 5
Feb 7 10:29:53.435 [INFO ] MEDIA: 865184752 ipp_mode: 0
Feb 7 10:29:53.435 [INFO ] MEDIA: CAudioTi::PlayCall: jb_mode 1 jb_min 0 jb_max 300 jb_avg 60
Feb 7 10:29:53.436 [INFO ] MEDIA: 865184752 PlayCall: pbPT 101 dtmf_type: 2
Feb 7 10:29:53.436 [INFO ] MEDIA: coding profile: 1 ptype: 0 ssrc: 654321 vad: 0 rate_idx: 0 dtmf_relay: 4 dtmf_pt: 101 vif: 1280/1280 0 65535
Feb 7 10:29:53.436 [INFO ] MEDIA: sec decoder: 0 0 0
Feb 7 10:29:53.436 [INFO ] MEDIA: 865184752 request_coding_params 0!
Feb 7 10:29:53.440 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:29:53.456 [INFO ] SIP: packet 1135333 stopped retransmission
Feb 7 10:29:53.457 [DEBUG0] SIP: connection 18 terminated
Feb 7 10:29:53.458 [INFO ] SIP: RTP: set_audible(0/0 -> 0/0): RP114 changed=0, update_req=0, adr=xxx.xxx.xxx.xxx:55952
Feb 7 10:29:53.458 [DEBUG0] MEDIA: MediaIpc::closeStream: cb0a16b4
Feb 7 10:29:53.461 [INFO ] SIP: rtp_port::release_turn_resources(), bw_check_enabled=0, rtp relay port=0, rtcp relay port=0
Feb 7 10:29:53.461 [INFO ] SIP: RTP: set_audible(0/0 -> 0/0): RP114 changed=0, update_req=0, adr=xxx.xxx.xxx.xxx:55952
Feb 7 10:29:53.461 [NOTICE] MEDIA: MediaIpc::rtpClose: RP114
Feb 7 10:29:53.461 [NOTICE] MEDIA: MediaIpc::rtpClose: RC114
Feb 7 10:29:53.472 [INFO ] SIP: ClearRefreshNotifyTimeout 313534393535323834303237363831-p10ij3kd99nq
Feb 7 10:29:53.477 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135336
Feb 7 10:29:53.477 [DEBUG0] SIP: send 200 NOTIFY (2: 313534393535323834303237363831-p10ij3kd99nq) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:29:53.653 [INFO ] PHN: WebImage::SetLocation http://%17:80
Feb 7 10:29:53.654 [INFO ] PHN: WebImage::SetLocation http://%17:80
Feb 7 10:29:54.671 [INFO ] MEDIA: 865186113 request_coding_profile_done!
Feb 7 10:29:54.671 [INFO ] MEDIA: 865186114 request_coding state 1
Feb 7 10:29:54.672 [INFO ] MEDIA: 865186116 check_coding_state: 6/6
Feb 7 10:29:54.672 [INFO ] MEDIA: 865186117 CAudioTi::SetInternAudioMode set_ipp_mode 0: 0->0 (0)!
Feb 7 10:29:54.672 [INFO ] MEDIA: 865186119 check_ipp_mode: 0/0
Feb 7 10:29:54.672 [INFO ] MEDIA: 865186128 SetConferenceLevelChannel(0, 1 0)
Feb 7 10:29:54.673 [INFO ] MEDIA: 865186128 Current gain row: 0, new row: 0!
Feb 7 10:29:54.673 [INFO ] MEDIA: 865186128 CAudioTi::PlayCall: active channels: 1
Feb 7 10:29:54.673 [INFO ] MEDIA: 865186128 CAudioTi::PlayCall: channel 0 active: 1 ssrc: 654321
Feb 7 10:29:54.674 [INFO ] MEDIA: 865186128 CAudioTi::PlayCall: channel 1 active: 0 ssrc: 0
Feb 7 10:29:54.674 [INFO ] MEDIA: 865186129 CAudioTi::PlayCall: channel 2 active: 0 ssrc: 0
Feb 7 10:29:54.674 [INFO ] MEDIA: 865186129 CAudioTi::PlayCall: channel 3 active: 0 ssrc: 0
Feb 7 10:29:54.674 [DEBUG0] MEDIA: StreamClose: 3406436020
Feb 7 10:29:54.675 [DEBUG0] MEDIA: close stream 3406436020 with packet_ssrc 1988925535
Feb 7 10:29:54.675 [NOTICE] MEDIA: onRtpClose: RP114
Feb 7 10:29:54.675 [DEBUG0] MEDIA: onRtpClose: name: RP114 ssrc: 3406436020
Feb 7 10:29:54.675 [INFO ] MEDIA: NumberOfSocketsWithSsrc: ssrc: 3406436020, sockets: 1
Feb 7 10:29:54.675 [INFO ] MEDIA: onRtpClose: Only one socket with ssrc 3406436020 found, call can be closed
Feb 7 10:29:54.676 [INFO ] MEDIA: 865186136 StopCall - ssrc: 3406436020
Feb 7 10:29:54.676 [DEBUG0] MEDIA: Socket 0x4e85f0/noname: state disconnected(7)
Feb 7 10:29:54.676 [DEBUG0] MEDIA: Socket 0x4e85f0/noname: state deleted(8)
Feb 7 10:29:54.676 [NOTICE] MEDIA: onRtpClose: RC114
Feb 7 10:29:54.676 [DEBUG0] MEDIA: onRtpClose: name: RC114 ssrc: 0
Feb 7 10:29:54.677 [INFO ] MEDIA: NumberOfSocketsWithSsrc: ssrc: 0, sockets: 0
Feb 7 10:29:54.677 [DEBUG0] MEDIA: Socket 0x4e8cd8/noname: state disconnected(7)
Feb 7 10:29:54.677 [DEBUG0] MEDIA: Socket 0x4e8cd8/noname: state deleted(8)
Feb 7 10:29:54.677 [INFO ] MEDIA: 865186141 datacallback: start sending: 654321 playstate: 0
Feb 7 10:30:07.855 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:30:07.862 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:30:10.352 [INFO ] PHN: WEB: Request 7791/72/0: GET / HTTP/1.1
Feb 7 10:30:10.353 [INFO ] PHN: WEB: 7791 Basic authentication.
Feb 7 10:30:10.353 [INFO ] PHN: Authentication triggered. Set flag back.
Feb 7 10:30:13.444 [DEBUG0] UXM: Request backlight for module -1 with value 1
Feb 7 10:30:25.701 [DEBUG0] SIP: refresh subscription 12 in 2308 sec
Feb 7 10:30:25.711 [DEBUG0] SIP: Use Connection Tls:xxx.xxx.xxx.xxx:5061 for packet 1135337
Feb 7 10:30:25.711 [DEBUG0] SIP: send SUBSCRIBE (8: 313534393535323834303237363831-p10ij3kd99nq) -> Tls:xxx.xxx.xxx.xxx:5061
Feb 7 10:30:25.728 [ERROR ] PHN: TPL: Socket Error: 7776/37/connected, Tls error, closing
Feb 7 10:30:25.731 [DEBUG0] SIP: sip::closed_reg_connection: reg=0
Feb 7 10:30:25.732 [INFO ] SIP: stop subscription 0/313534393535323834303237303638-gjhqa6xtyj2u
Feb 7 10:30:25.732 [INFO ] SIP: stop subscription 0/313534393535323834303237363831-p10ij3kd99nq
Feb 7 10:30:25.732 [INFO ] SIP: packet 0/1135337 stopped retransmission
Feb 7 10:30:25.732 [INFO ] SIP: stop subscription 0/313534393535323834303238323937-bix9b6glmqgs
Feb 7 10:30:25.733 [INFO ] SIP: stop subscription 0/313534393535323834303238373732-vq1hwbhpvszz
Feb 7 10:30:25.733 [INFO ] SIP: stop subscription 0/313534393535323834303239333933-cv01bskudfvd
Feb 7 10:30:25.733 [INFO ] SIP: Identity 1 reregister in 329000 ms.
Feb 7 10:30:25.734 [FATAL ] SIP: sip_transport_state_cb context lost
Feb 7 10:30:25.771 [INFO ] PHN: WebImage::SetLocation http://%1A:80
Feb 7 10:30:25.772 [INFO ] PHN: WebImage::SetLocation http://%1A:80
Feb 7 10:30:26.044 [DEBUG0] UXM: Request backlight for module -1 with value 15
Feb 7 10:30:26.075 [INFO ] PHN: WebImage::SetLocation http://%1A:80
Feb 7 10:30:26.075 [INFO ] PHN: WebImage::SetLocation http://%1A:80
Feb 7 10:30:27.188 [ERROR ] TLS: BIO_new_bio_pair code 336539714, error:140F3042:SSL routines:ssl_undefined_const_function:called a function you should not call
Feb 7 10:30:27.235 [INFO ] PHN: WEB: Request 7792/72/0: GET / HTTP/1.1
Feb 7 10:30:27.235 [INFO ] PHN: WEB: 7792 Basic authentication.
Feb 7 10:30:27.236 [INFO ] PHN: Authentication triggered. Set flag back.
Feb 7 10:30:37.857 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:30:38.455 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:30:42.782 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:30:46.045 [DEBUG0] UXM: Request backlight for module -1 with value 1
Feb 7 10:31:07.861 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:31:08.997 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:31:37.863 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:31:39.501 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:31:42.793 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:32:07.865 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:32:10.034 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:32:37.867 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:32:40.665 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:32:42.804 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:33:07.871 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:33:11.150 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:33:37.873 [INFO ] PHN: Watchdog: keep fd dog = 5
Feb 7 10:33:41.671 [INFO ] PHN: LLDP: No Voice Application Type TLV packet found
Feb 7 10:33:42.815 [INFO ] PHN: LLDP: Skipped packet (280 bytes), not from router/bridge
Feb 7 10:33:48.215 [INFO ] PHN: WEB: Request 7796/433/0: GET / HTTP/1.1
Feb 7 10:33:48.216 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:48.973 [DEBUG0] PHN: TaskMon: LCS/48864148 PollEvent took 758 msecs, started Feb 7 10:33:48
Feb 7 10:33:48.974 [DEBUG0] PHN: LoopMon: LCS/48864148 took 769 (49) msecs, started Feb 7 10:33:48, 8 tasks
Feb 7 10:33:49.101 [INFO ] PHN: WEB: Request 7796/380/0: GET /normal.css HTTP/1.1
Feb 7 10:33:49.101 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:49.113 [INFO ] PHN: WEB: Request 7796/377/0: GET /fox.css HTTP/1.1
Feb 7 10:33:49.113 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:49.143 [INFO ] PHN: WEB: Request 7796/402/0: GET /img/clr.gif HTTP/1.1
Feb 7 10:33:49.143 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:49.153 [INFO ] PHN: WEB: Request 7796/408/0: GET /img/snom_logo.png HTTP/1.1
Feb 7 10:33:49.154 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:49.679 [INFO ] PHN: WEB: Request 7796/408/0: GET /img/separater.png HTTP/1.1
Feb 7 10:33:49.680 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:49.693 [INFO ] PHN: WEB: Request 7796/404/0: GET /img/corul.gif HTTP/1.1
Feb 7 10:33:49.693 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:49.700 [INFO ] PHN: WEB: Request 7800/404/0: GET /img/corur.gif HTTP/1.1
Feb 7 10:33:49.702 [INFO ] PHN: WEB: 7800 Basic authentication.
Feb 7 10:33:49.706 [INFO ] PHN: WEB: Request 7796/404/0: GET /img/corll.gif HTTP/1.1
Feb 7 10:33:49.710 [INFO ] PHN: WEB: 7796 Basic authentication.
Feb 7 10:33:49.712 [INFO ] PHN: WEB: Request 7801/404/0: GET /img/corlr.gif HTTP/1.1
Feb 7 10:33:49.713 [INFO ] PHN: WEB: 7801 Basic authentication.
Feb 7 10:33:49.716 [INFO ] PHN: WEB: Request 7802/405/0: GET /img/delete.gif HTTP/1.1
Feb 7 10:33:49.716 [INFO ] PHN: WEB: 7802 Basic authentication.
Feb 7 10:33:49.722 [INFO ] PHN: WEB: Request 7800/403/0: GET /img/edit.gif HTTP/1.1
Feb 7 10:33:49.722 [INFO ] PHN: WEB: 7800 Basic authentication.
Feb 7 10:33:49.941 [INFO ] PHN: WEB: Request 7800/403/0: GET /img/head.png HTTP/1.1
Feb 7 10:33:49.942 [INFO ] PHN: WEB: 7800 Basic authentication.
Feb 7 10:33:51.971 [INFO ] PHN: WEB: Request 7800/474/0: GET /log.htm HTTP/1.1
Feb 7 10:33:51.971 [INFO ] PHN: WEB: 7800 Basic authentication.

any idea whats going on?

 

firewall is a Sophos UTM 9

session values got configured like in the attachment.

 

0.png

Share this post


Link to post
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.

Guest
Reply to this topic...

×   Pasted as rich text.   Paste as plain text instead

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

Loading...

×
×
  • Create New...