[Dec 22 13:47:36] Asterisk 16.9.0 built by jean @ pc-jean on a x86_64 running Linux on 2020-11-25 15:31:25 UTC [Dec 22 13:47:36] DEBUG[1884] config.c: Parsing /etc/asterisk/logger.conf [Dec 22 13:47:36] VERBOSE[1884] logger.c: Asterisk Queue Logger restarted [Dec 22 13:47:38] DEBUG[1916] chan_sip.c: = Looking for Call ID: 579113623-5060-63@BJC.BGI.BA.C (Checking From) --From tag 112193852 --To-tag [Dec 22 13:47:38] DEBUG[1916] acl.c: For destination '192.168.10.2', our source address is '192.168.10.1'. [Dec 22 13:47:38] DEBUG[1916] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.10.1:5060 [Dec 22 13:47:38] DEBUG[1916] netsock2.c: Splitting '192.168.10.2:5060' into... [Dec 22 13:47:38] DEBUG[1916] netsock2.c: ...host '192.168.10.2' and port '5060'. [Dec 22 13:47:38] DEBUG[1916] chan_sip.c: Allocating new SIP dialog for 579113623-5060-63@BJC.BGI.BA.C - INVITE (No RTP) [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 22 13:47:38] DEBUG[1916][C-00000006] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, path, timer" [Dec 22 13:47:38] DEBUG[1916][C-00000006] sip/reqresp_parser.c: Found SIP option: -replaces- [Dec 22 13:47:38] DEBUG[1916][C-00000006] sip/reqresp_parser.c: Matched SIP option: replaces [Dec 22 13:47:38] DEBUG[1916][C-00000006] sip/reqresp_parser.c: Found SIP option: -path- [Dec 22 13:47:38] DEBUG[1916][C-00000006] sip/reqresp_parser.c: Matched SIP option: path [Dec 22 13:47:38] DEBUG[1916][C-00000006] sip/reqresp_parser.c: Found SIP option: -timer- [Dec 22 13:47:38] DEBUG[1916][C-00000006] sip/reqresp_parser.c: Matched SIP option: timer [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.2:5060' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.2' and port '5060'. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.1' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.1' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x561de5b53200' [Dec 22 13:47:38] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Allocated port 30428 for RTP instance '0x561de5b53200' [Dec 22 13:47:38] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:30428 (30428) for RTP instance '0x561de5b53200' [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: TestEvent Privilege: reporting,all Type: StateChange State: RTP_PORT_ALLOCATED AppFile: res_rtp_asterisk.c AppFunction: rtp_allocate_transport AppLine: 4152 Port: 30428 [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.5.140' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.5.140' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.5.140' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.5.140' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.56.1' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.56.1' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.56.1' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.56.1' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.1' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.1' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.1' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.1' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '10.155.100.140' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '10.155.100.140' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '10.155.100.140' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '10.155.100.140' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: RTP instance '0x561de5b53200' is setup and ready to go [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting 'pc-jean' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host 'pc-jean' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x561de5b53200' [Dec 22 13:47:38] VERBOSE[1916][C-00000006] netsock2.c: Using SIP RTP TOS bits 184 [Dec 22 13:47:38] VERBOSE[1916][C-00000006] netsock2.c: Using SIP RTP CoS mark 5 [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Setting NAT on RTP to Off [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP o=phone 8000 8000 IN IP4 192.168.10.2... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.2' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.2' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.10.2... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Setting tx payload type 4 based on m type on 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Don't have a default tx payload type 2 format for m type on 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:4 G723/8000... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:97 iLBC/8000... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=fmtp:97 mode=30... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK. [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x561de57efe58) from 0x7f0d7f27f4f0 to 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 2 (0x561de5a6e868) from 0x7f0d7f27f4f0 to 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 4 (0x561de5a6eb48) from 0x7f0d7f27f4f0 to 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x561de58ec508) from 0x7f0d7f27f4f0 to 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 9 (0x561de5a6e7d8) from 0x7f0d7f27f4f0 to 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x561de5a6ebd8) from 0x7f0d7f27f4f0 to 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 97 (0x561de5f1ff88) from 0x7f0d7f27f4f0 to 0x7f0d7f27f4f0 [Dec 22 13:47:38] DEBUG[1916][C-00000006] acl.c: For destination '192.168.10.2', our source address is '192.168.10.1'. [Dec 22 13:47:38] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x561de5b53200' [Dec 22 13:47:38] VERBOSE[1916][C-00000006] res_rtp_asterisk.c: 0x561de5b4ba50 -- Strict RTP learning after remote address set to: 192.168.10.2:5004 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying rx payload mapping 0 (0x561de57efe58) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying rx payload mapping 2 (0x561de5a6e868) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying rx payload mapping 4 (0x561de5a6eb48) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying rx payload mapping 8 (0x561de58ec508) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying rx payload mapping 9 (0x561de5a6e7d8) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying rx payload mapping 18 (0x561de5a6ebd8) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying rx payload mapping 97 (0x561de5f1ff88) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 0 (0x561de57efe58) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 2 (0x561de5a6e868) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 4 (0x561de5a6eb48) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 8 (0x561de58ec508) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 9 (0x561de5a6e7d8) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 18 (0x561de5a6ebd8) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 97 (0x561de5f1ff88) from 0x7f0d7f27f4f0 to 0x561de5b533d8 [Dec 22 13:47:38] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x561de5b53200' [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: We're settling with these formats: (ulaw|alaw) [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Checking SIP call limits for device phone [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Updating call counter for incoming call [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.1' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.1' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.1' into... [Dec 22 13:47:38] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.1' and port ''. [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Incoming INVITE with 'timer' option supported [Dec 22 13:47:38] DEBUG[1916][C-00000006] stasis.c: Creating topic. name: channel:1608641258.15, detail: [Dec 22 13:47:38] DEBUG[1916][C-00000006] stasis.c: Topic 'channel:1608641258.15': 0x561de5c2bb90 created [Dec 22 13:47:38] DEBUG[1916][C-00000006] stasis.c: Creating topic. name: cache:31/channel:1608641258.15, detail: [Dec 22 13:47:38] DEBUG[1916][C-00000006] stasis.c: Topic 'cache:31/channel:1608641258.15': 0x561de56e24f0 created [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: Newchannel Privilege: call,all Channel: SIP/phone-0000000a ChannelState: 0 ChannelStateDesc: Down CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 [Dec 22 13:47:38] DEBUG[1916][C-00000006] channel.c: Channel 0x561de5c32b10 'SIP/phone-0000000a' allocated [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: *** Our native formats are (ulaw) [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: *** Joint capabilities are (ulaw|alaw) [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: *** Our capabilities are (ulaw|alaw|gsm|h263) [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: This channel will not be able to handle video. [Dec 22 13:47:38] NOTICE[1916][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[1916][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[1916][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: TestEvent Privilege: reporting,all Type: StateChange State: CallIDChange AppFile: channel_internal_api.c AppFunction: ast_channel_callid_set AppLine: 782 State: CallIDChange Channel: SIP/phone-0000000a CallID: [C-00000006] PriorCallID: [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: SIP/phone-0000000a: New call is still down.... Trying... [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.10.2:5060 [Dec 22 13:47:38] DEBUG[1898] devicestate.c: No provider found, checking channel drivers for SIP - phone [Dec 22 13:47:38] DEBUG[1898] chan_sip.c: Checking device state for peer phone [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: Newstate Privilege: call,all Channel: SIP/phone-0000000a ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 [Dec 22 13:47:38] DEBUG[1898] devicestate.c: Changing state for SIP/phone - state 1 (Not in use) [Dec 22 13:47:38] DEBUG[3433][C-00000006] pbx.c: Launching 'Dial' [Dec 22 13:47:38] VERBOSE[3433][C-00000006] pbx.c: Executing [203@default:1] Dial("SIP/phone-0000000a", "SIP/stephane") in new stack [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: Newexten Privilege: dialplan,all Channel: SIP/phone-0000000a ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 Extension: 203 Application: Dial AppData: SIP/stephane [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Asked to create a SIP channel with formats: (ulaw) [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Allocating new SIP dialog for 2ee29ae627a9bf56550185b3475dfb88@127.0.1.1:5060 - INVITE (No RTP) [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f0db80063e0' [Dec 22 13:47:38] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Allocated port 33570 for RTP instance '0x7f0db80063e0' [Dec 22 13:47:38] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:33570 (33570) for RTP instance '0x7f0db80063e0' [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: TestEvent Privilege: reporting,all Type: StateChange State: RTP_PORT_ALLOCATED AppFile: res_rtp_asterisk.c AppFunction: rtp_allocate_transport AppLine: 4152 Port: 33570 [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '192.168.5.140' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '192.168.5.140' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '192.168.5.140' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '192.168.5.140' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '192.168.56.1' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '192.168.56.1' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '192.168.56.1' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '192.168.56.1' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '192.168.10.1' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '192.168.10.1' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '192.168.10.1' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '192.168.10.1' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '10.155.100.140' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '10.155.100.140' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '10.155.100.140' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '10.155.100.140' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: RTP instance '0x7f0db80063e0' is setup and ready to go [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting 'pc-jean' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host 'pc-jean' and port ''. [Dec 22 13:47:38] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f0db80063e0' [Dec 22 13:47:38] VERBOSE[3433][C-00000006] netsock2.c: Using SIP RTP TOS bits 184 [Dec 22 13:47:38] VERBOSE[3433][C-00000006] netsock2.c: Using SIP RTP CoS mark 5 [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Setting NAT on RTP to Off [Dec 22 13:47:38] DEBUG[3433][C-00000006] acl.c: For destination '192.168.10.3', our source address is '192.168.10.1'. [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.10.1:5060 [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: Splitting '192.168.10.3:5060' into... [Dec 22 13:47:38] DEBUG[3433][C-00000006] netsock2.c: ...host '192.168.10.3' and port '5060'. [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Setting NAT on RTP to Off [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: SIP call-id changed from '2ee29ae627a9bf56550185b3475dfb88@127.0.1.1:5060' to '36c4159d012384575138b2a445af86a4@192.168.10.1:5060' [Dec 22 13:47:38] DEBUG[3433][C-00000006] stasis.c: Creating topic. name: channel:1608641258.16, detail: [Dec 22 13:47:38] DEBUG[3433][C-00000006] stasis.c: Topic 'channel:1608641258.16': 0x7f0db800c100 created [Dec 22 13:47:38] DEBUG[3433][C-00000006] stasis.c: Creating topic. name: cache:32/channel:1608641258.16, detail: [Dec 22 13:47:38] DEBUG[3433][C-00000006] stasis.c: Topic 'cache:32/channel:1608641258.16': 0x7f0db80270f0 created [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: Newchannel Privilege: call,all Channel: SIP/stephane-0000000b ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: s Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 [Dec 22 13:47:38] DEBUG[3433][C-00000006] channel.c: Channel 0x7f0db800a380 'SIP/stephane-0000000b' allocated [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: *** Our native formats are (ulaw) [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: *** Joint capabilities are (ulaw) [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: *** Our capabilities are (ulaw|alaw|gsm|h263) [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: *** Our preferred formats from the incoming channel are (ulaw) [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: This channel will not be able to handle video. [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: TestEvent Privilege: reporting,all Type: StateChange State: CallIDChange AppFile: channel_internal_api.c AppFunction: ast_channel_callid_set AppLine: 782 State: CallIDChange Channel: SIP/stephane-0000000b CallID: [C-00000006] PriorCallID: [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] DEBUG[3433][C-00000006] channel_internal_api.c: Channel Call ID changing from [C-00000006] to [C-00000006] [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: TestEvent Privilege: reporting,all Type: StateChange State: CallIDChange AppFile: channel_internal_api.c AppFunction: ast_channel_callid_set AppLine: 782 State: CallIDChange Channel: SIP/stephane-0000000b CallID: [C-00000006] PriorCallID: [C-00000006] [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x561de57efe58) from 0x561de5b533d8 to 0x7f0db80065b8 [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 2 (0x561de5a6e868) from 0x561de5b533d8 to 0x7f0db80065b8 [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 4 (0x561de5a6eb48) from 0x561de5b533d8 to 0x7f0db80065b8 [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x561de58ec508) from 0x561de5b533d8 to 0x7f0db80065b8 [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 9 (0x561de5a6e7d8) from 0x561de5b533d8 to 0x7f0db80065b8 [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x561de5a6ebd8) from 0x561de5b533d8 to 0x7f0db80065b8 [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Crossover copying tx to rx payload mapping 97 (0x561de5f1ff88) from 0x561de5b533d8 to 0x7f0db80065b8 [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Seeded SDP of 'SIP/stephane-0000000b' with that of 'SIP/phone-0000000a' [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Outgoing Call for stephane [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Updating call counter for outgoing call [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: Newexten Privilege: dialplan,all Channel: SIP/stephane-0000000b ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 Extension: 203 Application: AppDial AppData: (Outgoing Line) [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: NewCallerid Privilege: call,all Channel: SIP/stephane-0000000b ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 CID-CallingPres: 0 (Presentation Allowed, Not Screened) [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: NewConnectedLine Privilege: call,all Channel: SIP/stephane-0000000b ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: This call needs video offers, but there's no video support enabled! [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: ** Our capability: (ulaw|alaw|gsm|h263) Video flag: False Text flag: False [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: ** Our prefcodec: (ulaw) [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: -- Done with adding codecs to SDP [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|gsm|h263) [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Initializing initreq for method INVITE - callid 36c4159d012384575138b2a445af86a4@192.168.10.1:5060 [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.10.3:5060 [Dec 22 13:47:38] VERBOSE[3433][C-00000006] app_dial.c: Called SIP/stephane [Dec 22 13:47:38] DEBUG[3433][C-00000006] channel.c: Channel SIP/stephane-0000000b setting read format path: ulaw -> ulaw [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: DialBegin Privilege: call,all Channel: SIP/phone-0000000a ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 DestChannel: SIP/stephane-0000000b DestChannelState: 0 DestChannelStateDesc: Down DestCallerIDNum: 203 DestCallerIDName: DestConnectedLineNum: phone DestConnectedLineName: Grandstream DestLanguage: fr DestAccountCode: DestContext: default DestExten: 203 DestPriority: 1 DestUniqueid: 1608641258.16 DestLinkedid: 1608641258.15 DialString: stephane [Dec 22 13:47:38] DEBUG[3433][C-00000006] channel.c: Channel SIP/phone-0000000a setting write format path: ulaw -> ulaw [Dec 22 13:47:38] DEBUG[3433][C-00000006] channel.c: Channel SIP/phone-0000000a setting read format path: ulaw -> ulaw [Dec 22 13:47:38] DEBUG[3433][C-00000006] channel.c: Channel SIP/stephane-0000000b setting write format path: ulaw -> ulaw [Dec 22 13:47:38] DEBUG[1916] chan_sip.c: = Looking for Call ID: 36c4159d012384575138b2a445af86a4@192.168.10.1:5060 (Checking To) --From tag as091c01ae --To-tag [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '36c4159d012384575138b2a445af86a4@192.168.10.1:5060' Request 102: Found [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: SIP response 100 to standard invite [Dec 22 13:47:38] DEBUG[1916] chan_sip.c: = Looking for Call ID: 36c4159d012384575138b2a445af86a4@192.168.10.1:5060 (Checking To) --From tag as091c01ae --To-tag 958781654 [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '36c4159d012384575138b2a445af86a4@192.168.10.1:5060' Request 102: Found [Dec 22 13:47:38] DEBUG[1916][C-00000006] chan_sip.c: SIP response 180 to standard invite [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: Newstate Privilege: call,all Channel: SIP/stephane-0000000b ChannelState: 5 ChannelStateDesc: Ringing CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 [Dec 22 13:47:38] DEBUG[1898] devicestate.c: No provider found, checking channel drivers for SIP - stephane [Dec 22 13:47:38] DEBUG[1898] chan_sip.c: Checking device state for peer stephane [Dec 22 13:47:38] DEBUG[1898] devicestate.c: Changing state for SIP/stephane - state 1 (Not in use) [Dec 22 13:47:38] DEBUG[1898] devicestate.c: No provider found, checking channel drivers for SIP - stephane [Dec 22 13:47:38] DEBUG[1898] chan_sip.c: Checking device state for peer stephane [Dec 22 13:47:38] DEBUG[1898] devicestate.c: Changing state for SIP/stephane - state 1 (Not in use) [Dec 22 13:47:38] VERBOSE[3433][C-00000006] app_dial.c: SIP/stephane-0000000b is ringing [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: DeviceStateChange Privilege: call,all Device: SIP/stephane State: NOT_INUSE [Dec 22 13:47:38] DEBUG[3433][C-00000006] rtp_engine.c: Setting early bridge SDP of 'SIP/phone-0000000a' with that of 'SIP/stephane-0000000b' [Dec 22 13:47:38] DEBUG[3433][C-00000006] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 192.168.10.2:5060 [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:38] DEBUG[1933] manager.c: Examining AMI event: Event: DialState Privilege: call,all Channel: SIP/phone-0000000a ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 DestChannel: SIP/stephane-0000000b DestChannelState: 5 DestChannelStateDesc: Ringing DestCallerIDNum: 203 DestCallerIDName: DestConnectedLineNum: phone DestConnectedLineName: Grandstream DestLanguage: fr DestAccountCode: DestContext: default DestExten: 203 DestPriority: 1 DestUniqueid: 1608641258.16 DestLinkedid: 1608641258.15 DialStatus: RINGING [Dec 22 13:47:39] DEBUG[1916] chan_sip.c: Auto destroying SIP dialog '7fcd5b607016b1cb0fed32b9102bcc59@192.168.10.1:5060' [Dec 22 13:47:39] DEBUG[1916] chan_sip.c: Destroying SIP dialog 7fcd5b607016b1cb0fed32b9102bcc59@192.168.10.1:5060 [Dec 22 13:47:39] DEBUG[1916] rtp_engine.c: Destroyed RTP instance '0x7f0d8000fe00' [Dec 22 13:47:39] DEBUG[1933] manager.c: Running action 'Ping' [Dec 22 13:47:40] DEBUG[1916] chan_sip.c: = Looking for Call ID: 36c4159d012384575138b2a445af86a4@192.168.10.1:5060 (Checking To) --From tag as091c01ae --To-tag 958781654 [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Acked pending invite 102 [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Stopping retransmission on '36c4159d012384575138b2a445af86a4@192.168.10.1:5060' of Request 102: Match Found [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: SIP response 200 to standard invite [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP o=stephane 8000 8000 IN IP4 192.168.10.3... OK. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED. [Dec 22 13:47:40] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.3' into... [Dec 22 13:47:40] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.3' and port ''. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.10.3... OK. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Dec 22 13:47:40] DEBUG[1916][C-00000006] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f0d7f27f330 [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Dec 22 13:47:40] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Set role to CONTROLLING (0x7f0db80063e0) [Dec 22 13:47:40] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Set role failed; no ice instance (0x7f0db80063e0) [Dec 22 13:47:40] DEBUG[1916][C-00000006] acl.c: For destination '192.168.10.3', our source address is '192.168.10.1'. [Dec 22 13:47:40] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f0db80063e0' [Dec 22 13:47:40] VERBOSE[1916][C-00000006] res_rtp_asterisk.c: 0x7f0db80074d0 -- Strict RTP learning after remote address set to: 192.168.10.3:5004 [Dec 22 13:47:40] DEBUG[1916][C-00000006] rtp_engine.c: Copying tx payload mapping 8 (0x561de5b54508) from 0x7f0d7f27f330 to 0x7f0db80065b8 [Dec 22 13:47:40] DEBUG[1916][C-00000006] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f0db80063e0' [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: We're settling with these formats: (alaw) [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: We have an owner, now see if we need to change this call [Dec 22 13:47:40] DEBUG[1916][C-00000006] channel.c: Channel SIP/stephane-0000000b setting read format path: alaw -> ulaw [Dec 22 13:47:40] DEBUG[1916][C-00000006] channel.c: Channel SIP/stephane-0000000b setting write format path: ulaw -> alaw [Dec 22 13:47:40] DEBUG[1916][C-00000006] res_rtp_asterisk.c: ast_rtp_activate (0x7f0db80074d0) - setup and perform DTLS' [Dec 22 13:47:40] DEBUG[1916][C-00000006] res_rtp_asterisk.c: dtls_perform_handshake (0x7f0db80074d0) - ssl = (nil), setup = 0 [Dec 22 13:47:40] DEBUG[1916][C-00000006] res_rtp_asterisk.c: dtls_perform_handshake (0x7f0db80074d0) - ssl = (nil), setup = 0 [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Updating call counter for outgoing call [Dec 22 13:47:40] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.3:5060' into... [Dec 22 13:47:40] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.3' and port '5060'. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Session-Expires: 1800 [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Refresher: UAC [Dec 22 13:47:40] DEBUG[1916][C-00000006] netsock2.c: Splitting '192.168.10.3:5060' into... [Dec 22 13:47:40] DEBUG[1916][C-00000006] netsock2.c: ...host '192.168.10.3' and port '5060'. [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Trying to put 'ACK sip:ste' onto UDP socket destined for 192.168.10.3:5060 [Dec 22 13:47:40] DEBUG[1916] chan_sip.c: Session timer started: 2 - 36c4159d012384575138b2a445af86a4@192.168.10.1:5060 900000ms [Dec 22 13:47:40] DEBUG[1933] manager.c: Examining AMI event: Event: Newstate Privilege: call,all Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 [Dec 22 13:47:40] VERBOSE[3433][C-00000006] app_dial.c: SIP/stephane-0000000b answered SIP/phone-0000000a [Dec 22 13:47:40] DEBUG[1898] devicestate.c: No provider found, checking channel drivers for SIP - stephane [Dec 22 13:47:40] DEBUG[1898] chan_sip.c: Checking device state for peer stephane [Dec 22 13:47:40] DEBUG[1898] devicestate.c: Changing state for SIP/stephane - state 1 (Not in use) [Dec 22 13:47:40] DEBUG[3433][C-00000006] rtp_engine.c: Setting early bridge SDP of 'SIP/phone-0000000a' with that of 'SIP/stephane-0000000b' [Dec 22 13:47:40] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:40] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:40] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:40] DEBUG[1933] manager.c: Examining AMI event: Event: DialEnd Privilege: call,all Channel: SIP/phone-0000000a ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 DestChannel: SIP/stephane-0000000b DestChannelState: 6 DestChannelStateDesc: Up DestCallerIDNum: 203 DestCallerIDName: DestConnectedLineNum: phone DestConnectedLineName: Grandstream DestLanguage: fr DestAccountCode: DestContext: default DestExten: DestPriority: 1 DestUniqueid: 1608641258.16 DestLinkedid: 1608641258.15 DialStatus: ANSWER [Dec 22 13:47:40] DEBUG[3433][C-00000006] channel.c: Channel SIP/stephane-0000000b setting read format path: alaw -> alaw [Dec 22 13:47:40] DEBUG[3433][C-00000006] channel.c: Channel SIP/phone-0000000a setting write format path: alaw -> ulaw [Dec 22 13:47:40] DEBUG[3433][C-00000006] channel.c: Channel SIP/phone-0000000a setting read format path: ulaw -> ulaw [Dec 22 13:47:40] DEBUG[3433][C-00000006] chan_sip.c: SIP answering channel: SIP/phone-0000000a [Dec 22 13:47:40] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Setting the marker bit due to a source update [Dec 22 13:47:40] DEBUG[1898] devicestate.c: No provider found, checking channel drivers for SIP - phone [Dec 22 13:47:40] DEBUG[1898] chan_sip.c: Checking device state for peer phone [Dec 22 13:47:40] DEBUG[1898] devicestate.c: Changing state for SIP/phone - state 1 (Not in use) [Dec 22 13:47:40] DEBUG[3433][C-00000006] res_rtp_asterisk.c: ast_rtp_activate (0x561de5b4ba50) - setup and perform DTLS' [Dec 22 13:47:40] DEBUG[3433][C-00000006] res_rtp_asterisk.c: dtls_perform_handshake (0x561de5b4ba50) - ssl = (nil), setup = 0 [Dec 22 13:47:40] DEBUG[3433][C-00000006] res_rtp_asterisk.c: dtls_perform_handshake (0x561de5b4ba50) - ssl = (nil), setup = 0 [Dec 22 13:47:40] DEBUG[1933] manager.c: Examining AMI event: Event: Newstate Privilege: call,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 [Dec 22 13:47:40] DEBUG[3433][C-00000006] chan_sip.c: ** Our capability: (ulaw|alaw) Video flag: True Text flag: True [Dec 22 13:47:40] DEBUG[3433][C-00000006] chan_sip.c: ** Our prefcodec: (nothing) [Dec 22 13:47:40] DEBUG[3433][C-00000006] chan_sip.c: -- Done with adding codecs to SDP [Dec 22 13:47:40] DEBUG[3433][C-00000006] chan_sip.c: Setting framing on incoming call: 0 [Dec 22 13:47:40] DEBUG[3433][C-00000006] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw) [Dec 22 13:47:40] DEBUG[3433][C-00000006] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.10.2:5060 [Dec 22 13:47:40] DEBUG[1916] chan_sip.c: Session timer started: 8 - 579113623-5060-63@BJC.BGI.BA.C 900000ms [Dec 22 13:47:40] DEBUG[3433][C-00000006] stasis.c: Creating topic. name: bridge:101386c7-692b-4774-860a-f0649571d095, detail: [Dec 22 13:47:40] DEBUG[3433][C-00000006] stasis.c: Topic 'bridge:101386c7-692b-4774-860a-f0649571d095': 0x7f0db8003e00 created [Dec 22 13:47:40] DEBUG[3433][C-00000006] stasis.c: Creating topic. name: cache:33/bridge:101386c7-692b-4774-860a-f0649571d095, detail: [Dec 22 13:47:40] DEBUG[3433][C-00000006] stasis.c: Topic 'cache:33/bridge:101386c7-692b-4774-860a-f0649571d095': 0x7f0db8010640 created [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge_native_rtp.c: Bridge '101386c7-692b-4774-860a-f0649571d095' can not use native RTP bridge as two channels are required [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Chose bridge technology simple_bridge [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge 101386c7-692b-4774-860a-f0649571d095: calling simple_bridge technology constructor [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge 101386c7-692b-4774-860a-f0649571d095: calling simple_bridge technology start [Dec 22 13:47:40] DEBUG[1933] manager.c: Examining AMI event: Event: BridgeCreate Privilege: call,all BridgeUniqueid: 101386c7-692b-4774-860a-f0649571d095 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 0 BridgeVideoSourceMode: none [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge_channel.c: Bridge 101386c7-692b-4774-860a-f0649571d095: 0x7f0db8018c40(SIP/stephane-0000000b) is joining [Dec 22 13:47:40] DEBUG[1933] manager.c: Examining AMI event: Event: Newexten Privilege: dialplan,all Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 Extension: Application: AppDial AppData: (Outgoing Line) [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge_channel.c: Bridge 101386c7-692b-4774-860a-f0649571d095: pushing 0x7f0db8018c40(SIP/stephane-0000000b) [Dec 22 13:47:40] VERBOSE[3434][C-00000006] bridge_channel.c: Channel SIP/stephane-0000000b joined 'simple_bridge' basic-bridge <101386c7-692b-4774-860a-f0649571d095> [Dec 22 13:47:40] DEBUG[1933] manager.c: Examining AMI event: Event: BridgeEnter Privilege: call,all BridgeUniqueid: 101386c7-692b-4774-860a-f0649571d095 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 1 BridgeVideoSourceMode: none Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge_native_rtp.c: Bridge '101386c7-692b-4774-860a-f0649571d095' can not use native RTP bridge as two channels are required [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge.c: Bridge technology softmix does not have any capabilities we want. [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge.c: Chose bridge technology simple_bridge [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge.c: Bridge 101386c7-692b-4774-860a-f0649571d095 is already using the new technology. [Dec 22 13:47:40] DEBUG[3434][C-00000006] bridge.c: Bridge 101386c7-692b-4774-860a-f0649571d095: 0x7f0db8018c40(SIP/stephane-0000000b) is joining simple_bridge technology [Dec 22 13:47:40] DEBUG[3434][C-00000006] res_rtp_asterisk.c: Changing ssrc from 1691020727 to 614001129 due to a source change [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge_channel.c: Bridge 101386c7-692b-4774-860a-f0649571d095: 0x7f0db8011240(SIP/phone-0000000a) is joining [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge_channel.c: Bridge 101386c7-692b-4774-860a-f0649571d095: pushing 0x7f0db8011240(SIP/phone-0000000a) [Dec 22 13:47:40] VERBOSE[3433][C-00000006] bridge_channel.c: Channel SIP/phone-0000000a joined 'simple_bridge' basic-bridge <101386c7-692b-4774-860a-f0649571d095> [Dec 22 13:47:40] DEBUG[1933] manager.c: Examining AMI event: Event: BridgeEnter Privilege: call,all BridgeUniqueid: 101386c7-692b-4774-860a-f0649571d095 BridgeType: basic BridgeTechnology: simple_bridge BridgeCreator: BridgeName: BridgeNumChannels: 2 BridgeVideoSourceMode: none Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 [Dec 22 13:47:40] DEBUG[1906] cdr.c: Finalized CDR for SIP/stephane-0000000b - start 1608641258.967761 answer 1608641260.383814 end 1608641260.390233 dur 1.422 bill 0.006 dispo ANSWERED [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge_native_rtp.c: Bridge '101386c7-692b-4774-860a-f0649571d095'. Checking compatability for channels 'SIP/stephane-0000000b' and 'SIP/phone-0000000a' [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge_native_rtp.c: Bridge '101386c7-692b-4774-860a-f0649571d095': Channel codec0 = (alaw) is not codec1 = (ulaw), cannot native bridge in RTP. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge technology softmix does not have any capabilities we want. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Chose bridge technology simple_bridge [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge 101386c7-692b-4774-860a-f0649571d095 is already using the new technology. [Dec 22 13:47:40] DEBUG[3433][C-00000006] bridge.c: Bridge 101386c7-692b-4774-860a-f0649571d095: 0x7f0db8011240(SIP/phone-0000000a) is joining simple_bridge technology [Dec 22 13:47:40] DEBUG[3433][C-00000006] channel.c: Channel SIP/phone-0000000a setting read format path: ulaw -> ulaw [Dec 22 13:47:40] DEBUG[3433][C-00000006] channel.c: Channel SIP/stephane-0000000b setting read format path: alaw -> alaw [Dec 22 13:47:40] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:40] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:40] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:40] NOTICE[3433][C-00000006] stasis.c: Declining to allocate Stasis message type 'ast_channel_varset_type' due to configuration [Dec 22 13:47:40] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Changing ssrc from 354725360 to 1095830883 due to a source change [Dec 22 13:47:40] DEBUG[1916] chan_sip.c: = Looking for Call ID: 579113623-5060-63@BJC.BGI.BA.C (Checking From) --From tag 112193852 --To-tag as05938344 [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 22 13:47:40] DEBUG[1916][C-00000006] chan_sip.c: Stopping retransmission on '579113623-5060-63@BJC.BGI.BA.C' of Response 620: Match Found [Dec 22 13:47:40] VERBOSE[3434][C-00000006] res_rtp_asterisk.c: 0x7f0db80074d0 -- Strict RTP switching to RTP target address 192.168.10.3:5004 as source [Dec 22 13:47:40] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Ooh, format changed from none to ulaw [Dec 22 13:47:40] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x561de5b53200' [Dec 22 13:47:40] VERBOSE[3433][C-00000006] res_rtp_asterisk.c: 0x561de5b4ba50 -- Strict RTP switching to RTP target address 192.168.10.2:5004 as source [Dec 22 13:47:40] DEBUG[3434][C-00000006] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Dec 22 13:47:43] VERBOSE[3433][C-00000006] res_rtp_asterisk.c: 0x561de5b4ba50 -- Strict RTP learning complete - Locking on source address 192.168.10.2:5004 [Dec 22 13:47:43] DEBUG[1933] manager.c: Examining AMI event: Event: TestEvent Privilege: reporting,all Type: StateChange State: STRICT_RTP_LEARN AppFile: res_rtp_asterisk.c AppFunction: ast_rtp_read AppLine: 7981 Source: 192.168.10.2:5004 [Dec 22 13:47:45] VERBOSE[3434][C-00000006] res_rtp_asterisk.c: 0x7f0db80074d0 -- Strict RTP learning complete - Locking on source address 192.168.10.3:5004 [Dec 22 13:47:45] DEBUG[1933] manager.c: Examining AMI event: Event: TestEvent Privilege: reporting,all Type: StateChange State: STRICT_RTP_LEARN AppFile: res_rtp_asterisk.c AppFunction: ast_rtp_read AppLine: 7981 Source: 192.168.10.3:5004 [Dec 22 13:47:45] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 To: 192.168.10.3:5005 From: 192.168.10.1:33571 SSRC: 0x2498e9e9 PT: 200(SR) ReportCount: 1 SentNTP: 1608641265.489769 SentRTP: 20273120 SentPackets: 245 SentOctets: 39200 Report0SourceSSRC: 0x6a32cd52 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 18094 Report0SequenceNumberCycles: 0 Report0IAJitter: 16 Report0LSR: 0 Report0DLSR: 0.0000 [Dec 22 13:47:45] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.2:5005 From: 192.168.10.1:30429 SSRC: 0x41510d63 PT: 200(SR) ReportCount: 1 SentNTP: 1608641265.490339 SentRTP: 12587840 SentPackets: 250 SentOctets: 40000 Report0SourceSSRC: 0x19634aac Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 47124 Report0SequenceNumberCycles: 0 Report0IAJitter: 0 Report0LSR: 0 Report0DLSR: 0.0000 [Dec 22 13:47:45] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 192.168.10.2:5005 [Dec 22 13:47:45] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPReceived Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.1:30429 From: 192.168.10.2:5005 RTT: 0.0902 SSRC: 0x83d0d028 PT: 200(SR) ReportCount: 1 SentNTP: 2511272.664905 SentRTP: 2618724 SentPackets: 250 SentOctets: 40000 Report0SourceSSRC: 0x41510d63 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 29377 Report0SequenceNumberCycles: 0 Report0IAJitter: 3 Report0LSR: 1769045382 Report0DLSR: 0.0157 [Dec 22 13:47:46] DEBUG[3435] http.c: HTTP opening session. Top level [Dec 22 13:47:46] DEBUG[3435] http.c: HTTP Request URI is /ari/bridges?api_key=admin:admin [Dec 22 13:47:46] DEBUG[3435] http.c: match request [ari/bridges] with handler [httpstatus] len 10 [Dec 22 13:47:46] DEBUG[3435] http.c: match request [ari/bridges] with handler [ari] len 3 [Dec 22 13:47:46] DEBUG[3435] http.c: Match made with [ari] [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Finding handler for bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Finding handler for bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari sounds: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari asterisk: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari recordings: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari applications: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari events: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari playbacks: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari endpoints: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari deviceStates: Didn't match bridges [Dec 22 13:47:46] DEBUG[3435] res_ari.c: Checking ari bridges: Explicit match with bridges [Dec 22 13:47:46] DEBUG[3435] http.c: HTTP keeping session open. status_code:200 [Dec 22 13:47:49] DEBUG[1933] manager.c: Running action 'Ping' [Dec 22 13:47:50] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 To: 192.168.10.3:5005 From: 192.168.10.1:33571 SSRC: 0x2498e9e9 PT: 200(SR) ReportCount: 1 SentNTP: 1608641270.490766 SentRTP: 20313120 SentPackets: 495 SentOctets: 79200 Report0SourceSSRC: 0x6a32cd52 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 18344 Report0SequenceNumberCycles: 0 Report0IAJitter: 15 Report0LSR: 0 Report0DLSR: 0.0000 [Dec 22 13:47:50] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.2:5005 From: 192.168.10.1:30429 SSRC: 0x41510d63 PT: 200(SR) ReportCount: 1 SentNTP: 1608641270.491229 SentRTP: 12627840 SentPackets: 500 SentOctets: 80000 Report0SourceSSRC: 0x19634aac Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 47374 Report0SequenceNumberCycles: 0 Report0IAJitter: 1 Report0LSR: 3492325943 Report0DLSR: 4.8950 [Dec 22 13:47:50] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 192.168.10.2:5005 [Dec 22 13:47:50] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPReceived Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.1:30429 From: 192.168.10.2:5005 RTT: 0.0895 SSRC: 0x83d0d02d PT: 200(SR) ReportCount: 1 SentNTP: 2511277.727407 SentRTP: 2658724 SentPackets: 500 SentOctets: 80000 Report0SourceSSRC: 0x41510d63 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 29626 Report0SequenceNumberCycles: 0 Report0IAJitter: 0 Report0LSR: 1769373121 Report0DLSR: 0.0156 [Dec 22 13:47:55] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 To: 192.168.10.3:5005 From: 192.168.10.1:33571 SSRC: 0x2498e9e9 PT: 200(SR) ReportCount: 1 SentNTP: 1608641275.490539 SentRTP: 20353120 SentPackets: 745 SentOctets: 119200 Report0SourceSSRC: 0x6a32cd52 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 18594 Report0SequenceNumberCycles: 0 Report0IAJitter: 15 Report0LSR: 0 Report0DLSR: 0.0000 [Dec 22 13:47:55] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.2:5005 From: 192.168.10.1:30429 SSRC: 0x41510d63 PT: 200(SR) ReportCount: 1 SentNTP: 1608641275.490876 SentRTP: 12667840 SentPackets: 750 SentOctets: 120000 Report0SourceSSRC: 0x19634aac Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 47624 Report0SequenceNumberCycles: 0 Report0IAJitter: 2 Report0LSR: 3492657719 Report0DLSR: 4.8940 [Dec 22 13:47:55] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 192.168.10.2:5005 [Dec 22 13:47:55] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPReceived Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.1:30429 From: 192.168.10.2:5005 RTT: 0.0894 SSRC: 0x83d0d032 PT: 200(SR) ReportCount: 1 SentNTP: 2511282.789908 SentRTP: 2698724 SentPackets: 750 SentOctets: 120000 Report0SourceSSRC: 0x41510d63 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 29877 Report0SequenceNumberCycles: 0 Report0IAJitter: 0 Report0LSR: 1769700778 Report0DLSR: 0.0157 [Dec 22 13:47:57] DEBUG[3435] http.c: HTTP Request URI is /ari/bridges/101386c7-692b-4774-860a-f0649571d095?api_key=admin:admin [Dec 22 13:47:57] DEBUG[3435] http.c: match request [ari/bridges/101386c7-692b-4774-860a-f0649571d095] with handler [httpstatus] len 10 [Dec 22 13:47:57] DEBUG[3435] http.c: match request [ari/bridges/101386c7-692b-4774-860a-f0649571d095] with handler [ari] len 3 [Dec 22 13:47:57] DEBUG[3435] http.c: Match made with [ari] [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Finding handler for bridges/101386c7-692b-4774-860a-f0649571d095 [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Finding handler for bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari sounds: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari asterisk: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari recordings: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari applications: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari events: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari playbacks: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari endpoints: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari deviceStates: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari bridges: Explicit match with bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Finding handler for 101386c7-692b-4774-860a-f0649571d095 [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking bridges bridgeId: Matched wildcard. [Dec 22 13:47:57] DEBUG[3435] res_ari.c: No explicit handler found for 101386c7-692b-4774-860a-f0649571d095. Using wildcard bridgeId. [Dec 22 13:47:57] DEBUG[3435] http.c: HTTP keeping session open. status_code:204 [Dec 22 13:47:57] DEBUG[3435] http.c: HTTP Request URI is /ari/bridges/101386c7-692b-4774-860a-f0649571d095?api_key=admin:admin [Dec 22 13:47:57] DEBUG[3435] http.c: match request [ari/bridges/101386c7-692b-4774-860a-f0649571d095] with handler [httpstatus] len 10 [Dec 22 13:47:57] DEBUG[3435] http.c: match request [ari/bridges/101386c7-692b-4774-860a-f0649571d095] with handler [ari] len 3 [Dec 22 13:47:57] DEBUG[3435] http.c: Match made with [ari] [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Finding handler for bridges/101386c7-692b-4774-860a-f0649571d095 [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Finding handler for bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari sounds: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari asterisk: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari recordings: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari applications: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari events: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari playbacks: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari endpoints: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari deviceStates: Didn't match bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking ari bridges: Explicit match with bridges [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Finding handler for 101386c7-692b-4774-860a-f0649571d095 [Dec 22 13:47:57] DEBUG[3435] res_ari.c: Checking bridges bridgeId: Matched wildcard. [Dec 22 13:47:57] DEBUG[3435] res_ari.c: No explicit handler found for 101386c7-692b-4774-860a-f0649571d095. Using wildcard bridgeId. [Dec 22 13:47:57] ERROR[3435] res_ari_bridges.c: Invalid error response 409 for /bridges/{bridgeId} [Dec 22 13:47:57] ERROR[3435] res_ari_bridges.c: Response validation failed for /bridges/{bridgeId} [Dec 22 13:47:57] DEBUG[3435] http.c: HTTP keeping session open. status_code:500 [Dec 22 13:47:59] DEBUG[1933] manager.c: Running action 'Ping' [Dec 22 13:48:00] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 To: 192.168.10.3:5005 From: 192.168.10.1:33571 SSRC: 0x2498e9e9 PT: 200(SR) ReportCount: 1 SentNTP: 1608641280.490714 SentRTP: 20393120 SentPackets: 995 SentOctets: 159200 Report0SourceSSRC: 0x6a32cd52 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 18845 Report0SequenceNumberCycles: 0 Report0IAJitter: 14 Report0LSR: 0 Report0DLSR: 0.0000 [Dec 22 13:48:00] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.2:5005 From: 192.168.10.1:30429 SSRC: 0x41510d63 PT: 200(SR) ReportCount: 1 SentNTP: 1608641280.491072 SentRTP: 12708000 SentPackets: 1001 SentOctets: 160160 Report0SourceSSRC: 0x19634aac Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 47874 Report0SequenceNumberCycles: 0 Report0IAJitter: 2 Report0LSR: 3492989495 Report0DLSR: 4.8950 [Dec 22 13:48:00] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 192.168.10.2:5005 [Dec 22 13:48:00] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPReceived Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.1:30429 From: 192.168.10.2:5005 RTT: 0.0893 SSRC: 0x83d0d037 PT: 200(SR) ReportCount: 1 SentNTP: 2511287.883660 SentRTP: 2738724 SentPackets: 1000 SentOctets: 160000 Report0SourceSSRC: 0x41510d63 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 30127 Report0SequenceNumberCycles: 0 Report0IAJitter: 0 Report0LSR: 1770028470 Report0DLSR: 0.0154 [Dec 22 13:48:05] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/stephane-0000000b ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 203 CallerIDName: ConnectedLineNum: phone ConnectedLineName: Grandstream Language: fr AccountCode: Context: default Exten: Priority: 1 Uniqueid: 1608641258.16 Linkedid: 1608641258.15 To: 192.168.10.3:5005 From: 192.168.10.1:33571 SSRC: 0x2498e9e9 PT: 200(SR) ReportCount: 1 SentNTP: 1608641285.490115 SentRTP: 20433120 SentPackets: 1245 SentOctets: 199200 Report0SourceSSRC: 0x6a32cd52 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 19095 Report0SequenceNumberCycles: 0 Report0IAJitter: 15 Report0LSR: 0 Report0DLSR: 0.0000 [Dec 22 13:48:05] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPSent Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.2:5005 From: 192.168.10.1:30429 SSRC: 0x41510d63 PT: 200(SR) ReportCount: 1 SentNTP: 1608641285.490455 SentRTP: 12748000 SentPackets: 1251 SentOctets: 200160 Report0SourceSSRC: 0x19634aac Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 48124 Report0SequenceNumberCycles: 0 Report0IAJitter: 2 Report0LSR: 3493323319 Report0DLSR: 4.8940 [Dec 22 13:48:05] DEBUG[3433][C-00000006] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 192.168.10.2:5005 [Dec 22 13:48:05] DEBUG[1933] manager.c: Examining AMI event: Event: RTCPReceived Privilege: reporting,all Channel: SIP/phone-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: phone CallerIDName: Grandstream ConnectedLineNum: ConnectedLineName: Language: fr AccountCode: Context: default Exten: 203 Priority: 1 Uniqueid: 1608641258.15 Linkedid: 1608641258.15 To: 192.168.10.1:30429 From: 192.168.10.2:5005 RTT: 0.0898 SSRC: 0x83d0d03c PT: 200(SR) ReportCount: 1 SentNTP: 2511292.946162 SentRTP: 2778724 SentPackets: 1250 SentOctets: 200000 Report0SourceSSRC: 0x41510d63 Report0FractionLost: 0 Report0CumulativeLost: 0 Report0HighestSequence: 30377 Report0SequenceNumberCycles: 0 Report0IAJitter: 0 Report0LSR: 1770356110 Report0DLSR: 0.0157